No Audio - FS not doing NAT

672 views
Skip to first unread message

rajesh,beaconnetx

unread,
Dec 18, 2014, 12:15:29 AM12/18/14
to 2600h...@googlegroups.com
Hi 2600hz experts, James, Darren,

We are having issue with no voice path with Kazoo load -R15B-3.16-35.
The issue is that both devices are getting an internal IP address of FS instead of public IP in SIP SDP message even though public IP address is defined in sipinterface_1.xml
We are running Kamailio and Freeswitch on two different Amazon EC2 machine. We understand from various post that the Kamailio act as a SBC for SIP Signalling while Freeswitch act as Border GW for RTP traffic. Is our understanding correct that the Freeswitch to do NAT for media RTP?

I am hoping someone can help us resolve rtp issue?

Kamailio and CouchDB on one server (internal IP 172.31.38.228 - public IP xx.172.197.98)

kazoo-librabbitmq-master-0.el6.x86_64
kazoo-kamailio-4.0-46.el6.x86_64
kazoo-ui-v3.16-2.el6.noarch
kazoo-configs-3.16-8.el6.noarch
kazoo-json-c-master-0.el6.x86_64
kazoo-R15B-3.16-35.el6.x86_64
kazoo-bigcouch-R15B-0.4.x-1.el6.x86_64

[root@ip-172-31-38-228 kamailio]# netstat -anp | grep 5060
tcp        0      0 172.31.38.228:5060          0.0.0.0:*                   LISTEN      1601/kamailio       
udp        0      0 172.31.38.228:5060          0.0.0.0:*                               1509/kamailio    


local.cfg - 
listen=UDP_SIP 172.31.38.228:5060 advertise xx.172.197.98:5060
listen=TCP_SIP 172.31.38.228:5060 advertise xx.172.197.98:5060
listen=UDP_ALG_SIP
listen=TCP_ALG_SIP

dispatcher file -1 sip:172.31.32.243:11000 2


Freeswitch on other server ( internal IP 172.31.32.243 - public IP xx.172.103.138)
kazoo-prompts-3.0-0.el6.noarch
kazoo-configs-3.16-8.el6.noarch
kazoo-freeswitch-R15B-1.4.7-4.el6.x86_64

[root@ip-172-31-32-243 freeswitch]# netstat -anp | grep 11000
tcp        0      0 172.31.32.243:11000         0.0.0.0:*                   LISTEN      1370/freeswitch     
udp        0      0 172.31.32.243:11000         0.0.0.0:*                               1370/freeswitch  

=================================================================================================
Name             sipinterface_1
Domain Name       N/A
Auto-NAT         false
DBName           sofia_reg_sipinterface_1
Pres Hosts      
Dialplan         XML
Context           context_2
Challenge Realm   auto_from
RTP-IP           172.31.32.243
Ext-RTP-IP       xx.172.103.138
SIP-IP           172.31.32.243
Ext-SIP-IP       xx.172.103.138
URL               sip:mod_...@xx.172.103.138:11000
BIND-URL         sip:mod_...@xx.172.103.138:11000;maddr=172.31.32.243;transport=udp,tcp
HOLD-MUSIC       local_stream://default
OUTBOUND-PROXY   N/A
CODECS IN         H263,OPUS,G7221@32000h,G7221@16000h,G722,PCMU,PCMA,G729,GSM,Speex
CODECS OUT       H263,OPUS,G7221@32000h,G7221@16000h,G722,PCMU,PCMA,G729,GSM,Speex
TEL-EVENT         101
DTMF-MODE         rfc2833
CNG               13
SESSION-TO       0
MAX-DIALOG       1000
NOMEDIA           false
LATE-NEG         true
PROXY-MEDIA       false
ZRTP-PASSTHRU     false
AGGRESSIVENAT     false
CALLS-IN         0
FAILED-CALLS-IN   0
CALLS-OUT         0
FAILED-CALLS-OUT 0
REGISTRATIONS     0

Node          : whistl...@ip-172-31-38-228.ec2.internal
Version       : R15B03
Memory Usage  : 38.65MB
Processes     : 1633
Ports         : 33
Zone          : local
Broker        : amqp://guest:gu...@127.0.0.1:5672
WhApps        : callflow            camper              cdr                 conference          
                crossbar            fax                 hangups             media_mgr           
                milliwatt           notify              omnipresence        pivot               
                registrar           reorder             stepswitch          sysconf             
                trunkstore          

Node          : ecal...@ip-172-31-38-228.ec2.internal
Version       : R15B03
Memory Usage  : 24.08MB
Processes     : 996
Ports         : 46
Zone          : local
Broker        : amqp://guest:gu...@127.0.0.1:5672
WhApps        : ecallmgr            
Channels      : 0
Registrations : 1
Media Servers : frees...@ip-172-31-32-243.ec2.internal




Freeswitch debug.log - 
 ------------------------------------------------------------------------
recv 931 bytes from udp/[172.31.38.228]:5060 at 05:02:35.505085:
   ------------------------------------------------------------------------
   INVITE sip:20...@test.com:5060 SIP/2.0
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464>
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944
   From: "2001" <sip:20...@test.com>;tag=2022011464
   Call-ID: 9411...@24.13.173.136
   CSeq: 1 INVITE
   Content-Type: application/sdp
   Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
   Max-Forwards: 50
   User-Agent: Yealink SIP-T20P 9.72.0.30
   Proxy-Require: 0
   Supported: replaces
   Allow-Events: talk,hold,conference,refer,check-sync
   Content-Length: 181
   X-AUTH-IP: 24.13.173.136
   
   v=0
   o=- 20184 20184 IN IP4 24.13.173.136
   s=SDP data
   c=IN IP4 24.13.173.136
   t=0 0
   m=audio 11796 RTP/AVP 0 8
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=ptime:20
   a=sendrecv
   ------------------------------------------------------------------------
send 407 bytes to udp/[172.31.38.228]:5060 at 05:02:35.505452:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0;received=172.31.38.228
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464>
   From: "2001" <sip:20...@test.com>;tag=2022011464
   Call-ID: 9411...@24.13.173.136
   CSeq: 1 INVITE
   User-Agent: 2600hz
   Content-Length: 0
   
   ------------------------------------------------------------------------
9411...@24.13.173.136 2014-12-18 05:02:35.487887 [NOTICE] switch_channel.c:1054 New Channel sofia/sipinterface_1/20...@test.com [9411...@24.13.173.136]
9411...@24.13.173.136 2014-12-18 05:02:35.487887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:35.487887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:35.507926 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@test.com) Running State Change CS_NEW
9411...@24.13.173.136 2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8703 sofia/sipinterface_1/20...@test.com receiving invite from 172.31.38.228:5060 version: 1.4.7  64bit
2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8825 1 acls to check for proxy
2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8830 checking 172.31.38.228 against acl authoritative
2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8870 IP 172.31.38.228 Rejected by acl "authoritative". Falling back to Digest auth.
2014-12-18 05:02:35.507926 [DEBUG] sofia_reg.c:3345 sofia pre-register disabled...@24.13.173.136 2014-12-18 05:02:35.507926 [DEBUG] switch_core_state_machine.c:489 (sofia/sipinterface_1/20...@test.com) State NEW
send 842 bytes to udp/[172.31.38.228]:5060 at 05:02:35.509803:
   ------------------------------------------------------------------------
   SIP/2.0 407 Proxy Authentication Required
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0;received=172.31.38.228
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944
   From: "2001" <sip:20...@test.com>;tag=2022011464
   To: <sip:20...@test.com>;tag=0FjpQUg9cU1eH
   Call-ID: 9411...@24.13.173.136
   CSeq: 1 INVITE
   User-Agent: 2600hz
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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
   Proxy-Authenticate: Digest realm="test.com", nonce="14ba98b8-8673-11e4-9587-4be03abd148f", algorithm=MD5, qop="auth"
   Content-Length: 0
   
   ------------------------------------------------------------------------
9411...@24.13.173.136 2014-12-18 05:02:35.507926 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
2014-12-18 05:02:35.507926 [DEBUG] sofia.c:2033 detaching session 9411...@24.13.173.136
recv 281 bytes from udp/[172.31.38.228]:5060 at 05:02:35.510682:
   ------------------------------------------------------------------------
   ACK sip:20...@test.com:5060 SIP/2.0
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0
   From: "2001" <sip:20...@test.com>;tag=2022011464
   To: <sip:20...@test.com>;tag=0FjpQUg9cU1eH
   Call-ID: 9411...@24.13.173.136
   CSeq: 1 ACK
   Max-Forwards: 50
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 1172 bytes from udp/[172.31.38.228]:5060 at 05:02:35.688752:
   ------------------------------------------------------------------------
   INVITE sip:20...@test.com:5060 SIP/2.0
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464>
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bKfb11.54a11eb7.0
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1522596139
   From: "2001" <sip:20...@test.com>;tag=2022011464
   Call-ID: 9411...@24.13.173.136
   CSeq: 2 INVITE
   Proxy-Authorization: Digest username="2001", realm="test.com", nonce="14ba98b8-8673-11e4-9587-4be03abd148f", uri="sip:20...@test.com:5060", response="d6ad5d56c648be2bd46e8ddcd4359db3", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000001
   Content-Type: application/sdp
   Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
   Max-Forwards: 50
   User-Agent: Yealink SIP-T20P 9.72.0.30
   Proxy-Require: 0
   Supported: replaces
   Allow-Events: talk,hold,conference,refer,check-sync
   Content-Length: 181
   X-AUTH-IP: 24.13.173.136
   
   v=0
   o=- 20184 20184 IN IP4 24.13.173.136
   s=SDP data
   c=IN IP4 24.13.173.136
   t=0 0
   m=audio 11796 RTP/AVP 0 8
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=ptime:20
   a=sendrecv
   ------------------------------------------------------------------------
send 407 bytes to udp/[172.31.38.228]:5060 at 05:02:35.689006:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bKfb11.54a11eb7.0;received=172.31.38.228
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1522596139
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464>
   From: "2001" <sip:20...@test.com>;tag=2022011464
   Call-ID: 9411...@24.13.173.136
   CSeq: 2 INVITE
   User-Agent: 2600hz
   Content-Length: 0
   
   ------------------------------------------------------------------------
2014-12-18 05:02:35.687887 [DEBUG] sofia.c:2138 Re-attaching to session 9411...@24.13.173.136
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] sofia.c:8703 sofia/sipinterface_1/20...@test.com receiving invite from 172.31.38.228:5060 version: 1.4.7  64bit
2014-12-18 05:02:35.687887 [DEBUG] sofia.c:8825 1 acls to check for proxy
2014-12-18 05:02:35.687887 [DEBUG] sofia.c:8830 checking 172.31.38.228 against acl authoritative
2014-12-18 05:02:35.687887 [DEBUG] sofia.c:8870 IP 172.31.38.228 Rejected by acl "authoritative". Falling back to Digest auth.
2014-12-18 05:02:35.687887 [DEBUG] switch_xml.c:2009 Cache Info - Time Now : 1418878955 - Expires : 1418882489
2014-12-18 05:02:35.687887 [DEBUG] switch_xml.c:2015 20...@test.com fetched from cache
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@test.com entering state [received][100]
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] sofia.c:6423 Remote SDP:
9411...@24.13.173.136 o=- 20184 20184 IN IP4 24.13.173.136
9411...@24.13.173.136 c=IN IP4 24.13.173.136
9411...@24.13.173.136 m=audio 11796 RTP/AVP 0 8
9411...@24.13.173.136 a=rtpmap:0 PCMU/8000
9411...@24.13.173.136 a=rtpmap:8 PCMA/8000
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] sofia.c:6678 (sofia/sipinterface_1/20...@test.com) State Change CS_NEW -> CS_INIT
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@test.com) Running State Change CS_INIT
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:510 (sofia/sipinterface_1/20...@test.com) State INIT
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] mod_sofia.c:87 sofia/sipinterface_1/20...@test.com SOFIA INIT
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/20...@test.com Standard INIT
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/20...@test.com) State Change CS_INIT -> CS_ROUTING
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:510 (sofia/sipinterface_1/20...@test.com) State INIT going to sleep
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@test.com) Running State Change CS_ROUTING
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_channel.c:2179 (sofia/sipinterface_1/20...@test.com) Callstate Change DOWN -> RINGING
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:526 (sofia/sipinterface_1/20...@test.com) State ROUTING
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] mod_sofia.c:123 sofia/sipinterface_1/20...@test.com SOFIA ROUTING
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [DEBUG] switch_core_state_machine.c:164 sofia/sipinterface_1/20...@test.com Standard ROUTING
9411...@24.13.173.136 2014-12-18 05:02:35.687887 [INFO] mod_dialplan_xml.c:558 Processing 2001 <2001>->2002 in context context_2
2014-12-18 05:02:35.687887 [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request (14d6f7f6-8673-11e4-9589-4be03abd148f) to ecal...@ip-172-31-38-228.ec2.internal <3.4391.0>
2014-12-18 05:02:35.807887 [DEBUG] kazoo_node.c:1100 Sent erlang message to ecal...@ip-172-31-38-228.ec2.internal <3.4391.0>
2014-12-18 05:02:35.807887 [DEBUG] kazoo_fetch_agent.c:277 Received dialplan XML (14d6f7f6-8673-11e4-9589-4be03abd148f) after 120ms: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|ecal...@ip-172-31-38-228.ec2.internal won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=ecal...@ip-172-31-38-228.ec2.internal"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="park"/></condition></extension></context></section></document>
9411...@24.13.173.136 Dialplan: sofia/sipinterface_1/20...@test.com parsing [context_2->park] continue=false
9411...@24.13.173.136 |--- Dialplan: Processing recursive conditions level:1 [park_recur_1] require-nested=TRUE
9411...@24.13.173.136 |--- Dialplan: sofia/sipinterface_1/20...@test.com Regex (PASS) [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/ break=on-false
9411...@24.13.173.136 |--- Dialplan: sofia/sipinterface_1/20...@test.com Action export(ecallmgr_Bridge-ID=${UUID})
9411...@24.13.173.136 Dialplan: sofia/sipinterface_1/20...@test.com Absolute Condition [park]
9411...@24.13.173.136 Dialplan: sofia/sipinterface_1/20...@test.com Action log(NOTICE log|${uuid}|ecal...@ip-172-31-38-228.ec2.internal won call control)
9411...@24.13.173.136 Dialplan: sofia/sipinterface_1/20...@test.com Action export(ecallmgr_Ecallmgr-Node=ecal...@ip-172-31-38-228.ec2.internal)
9411...@24.13.173.136 Dialplan: sofia/sipinterface_1/20...@test.com Action set(ringback=%(2000,4000,440,480))
9411...@24.13.173.136 Dialplan: sofia/sipinterface_1/20...@test.com Action set(transfer_ringback=%(2000,4000,440,480))
9411...@24.13.173.136 Dialplan: sofia/sipinterface_1/20...@test.com Action park()
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_core_state_machine.c:214 (sofia/sipinterface_1/20...@test.com) State Change CS_ROUTING -> CS_EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_core_state_machine.c:526 (sofia/sipinterface_1/20...@test.com) State ROUTING going to sleep
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@test.com) Running State Change CS_EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_core_state_machine.c:533 (sofia/sipinterface_1/20...@test.com) State EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] mod_sofia.c:178 sofia/sipinterface_1/20...@test.com SOFIA EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_core_state_machine.c:256 sofia/sipinterface_1/20...@test.com Standard EXECUTE
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com export(ecallmgr_Bridge-ID=9411...@24.13.173.136)
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_channel.c:1246 EXPORT (export_vars) [ecallmgr_Bridge-ID]=[9411...@24.13.173.136]
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com log(NOTICE log|9411...@24.13.173.136|ecal...@ip-172-31-38-228.ec2.internal won call control)
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [NOTICE] mod_dptools.c:1667 log|9411...@24.13.173.136|ecal...@ip-172-31-38-228.ec2.internal won call control
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com export(ecallmgr_Ecallmgr-Node=ecal...@ip-172-31-38-228.ec2.internal)
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] switch_channel.c:1246 EXPORT (export_vars) [ecallmgr_Ecallmgr-Node]=[ecal...@ip-172-31-38-228.ec2.internal]
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com set(ringback=%(2000,4000,440,480))
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] mod_dptools.c:1435 sofia/sipinterface_1/20...@test.com SET [ringback]=[%(2000,4000,440,480)]
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com set(transfer_ringback=%(2000,4000,440,480))
9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG] mod_dptools.c:1435 sofia/sipinterface_1/20...@test.com SET [transfer_ringback]=[%(2000,4000,440,480)]
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com park()
2014-12-18 05:02:36.007891 [DEBUG] kazoo_node.c:1100 Sent erlang message to ecal...@ip-172-31-38-228.ec2.internal <3.4943.0>
2014-12-18 05:02:36.047887 [INFO] kazoo_node.c:625 exec: uuid_setvar_multi(9411...@24.13.173.136 effective_caller_id_name=2001;effective_caller_id_number=2001;ecallmgr_Fetch-ID=14d6f7f6-8673-11e4-9589-4be03abd148f;ecallmgr_Username=2001;ecallmgr_Realm=test.com;ecallmgr_Account-ID=5174fd7222418d0fb343cf577026d9d4;ecallmgr_Authorizing-ID=02e0214ede86ab71c07ff8825f3eb389;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=9daa6151cc9dc382d48744fd3fb522e7;ecallmgr_Account-Realm=test.com;ecallmgr_Account-Name=test;presence_id=20...@test.com)
2014-12-18 05:02:36.247887 [DEBUG] kazoo_node.c:1100 Sent erlang message to ecal...@ip-172-31-38-228.ec2.internal <3.4979.0>
2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302 log|9411...@24.13.173.136|building xferext extension: set continue_on_fail=true
2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302 log|9411...@24.13.173.136|building xferext extension: export sip_redirect_context=context_2
2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302 log|9411...@24.13.173.136|building xferext extension: export ecallmgr_Inception=${ecallmgr_Inception}
2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302 log|9411...@24.13.173.136|building xferext extension: bridge {call_timeout=20,originate_timeout=20,local_var_clobber='true'}[ecallmgr_Authorizing-ID='22003c5c65e877bacc440e8da962ee5a',ecallmgr_Owner-ID='3210f77460b685eeaa93d04fd0871945',ecallmgr_Account-ID='5174fd7222418d0fb343cf577026d9d4',sdp_secure_savp_only='false',sip_invite_domain='test.com',presence_id='20...@test.com',absolute_codec_string='^^:PCMU:PCMA',leg_timeout='20',effective_callee_id_number='2002',effective_callee_id_name='2002',origination_callee_id_number='2002',origination_callee_id_name='2002',ecallmgr_Realm='test.com',ecallmgr_Username='2002']sofia/sipinterface_1/20...@24.13.173.136:5062;fs_path=sip:172.31.38.228:5060;lr;received='sip:24.13.173.136:5062'
2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302 log|9411...@24.13.173.136|building xferext extension: event Event-Name=CUSTOM,Event-Subclass=whistle::masquerade,whistle_event_name=CHANNEL_EXECUTE_COMPLETE,whistle_application_name=bridge
2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302 log|9411...@24.13.173.136|building xferext extension: park 
2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:305 log|9411...@24.13.173.136|transfered call to xferext extension
9411...@24.13.173.136 2014-12-18 05:02:36.247887 [DEBUG] switch_core_session.c:1187 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_channel.c:3098 (sofia/sipinterface_1/20...@test.com) State Change CS_EXECUTE -> CS_ROUTING
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:533 (sofia/sipinterface_1/20...@test.com) State EXECUTE going to sleep
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@test.com) Running State Change CS_ROUTING
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:526 (sofia/sipinterface_1/20...@test.com) State ROUTING
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] mod_sofia.c:123 sofia/sipinterface_1/20...@test.com SOFIA ROUTING
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:164 sofia/sipinterface_1/20...@test.com Standard ROUTING
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:184 (sofia/sipinterface_1/20...@test.com) State Change CS_ROUTING -> CS_EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:526 (sofia/sipinterface_1/20...@test.com) State ROUTING going to sleep
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@test.com) Running State Change CS_EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:533 (sofia/sipinterface_1/20...@test.com) State EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] mod_sofia.c:178 sofia/sipinterface_1/20...@test.com SOFIA EXECUTE
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:256 sofia/sipinterface_1/20...@test.com Standard EXECUTE
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com set(continue_on_fail=true)
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] mod_dptools.c:1435 sofia/sipinterface_1/20...@test.com SET [continue_on_fail]=[true]
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com export(sip_redirect_context=context_2)
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_channel.c:1246 EXPORT (export_vars) [sip_redirect_context]=[context_2]
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com export(ecallmgr_Inception=)
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_channel.c:1246 EXPORT (export_vars) [ecallmgr_Inception]=[UNDEF]
9411...@24.13.173.136 EXECUTE sofia/sipinterface_1/20...@test.com bridge({call_timeout=20,originate_timeout=20,local_var_clobber=true}[ecallmgr_Authorizing-ID=22003c5c65e877bacc440e8da962ee5a,ecallmgr_Owner-ID=3210f77460b685eeaa93d04fd0871945,ecallmgr_Account-ID=5174fd7222418d0fb343cf577026d9d4,sdp_secure_savp_only=false,sip_invite_domain=test.com,presence_id=20...@test.com,absolute_codec_string=^^:PCMU:PCMA,leg_timeout=20,effective_callee_id_number=2002,effective_callee_id_name=2002,origination_callee_id_number=2002,origination_callee_id_name=2002,ecallmgr_Realm=test.com,ecallmgr_Username=2002]sofia/sipinterface_1/20...@24.13.173.136:5062;fs_path=sip:172.31.38.228:5060;lr;received=sip:24.13.173.136:5062)
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_channel.c:1200 sofia/sipinterface_1/20...@test.com EXPORTING[export_vars] [ecallmgr_Bridge-ID]=[9411...@24.13.173.136] to event
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_channel.c:1200 sofia/sipinterface_1/20...@test.com EXPORTING[export_vars] [ecallmgr_Ecallmgr-Node]=[ecal...@ip-172-31-38-228.ec2.internal] to event
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_channel.c:1200 sofia/sipinterface_1/20...@test.com EXPORTING[export_vars] [sip_redirect_context]=[context_2] to event
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_ivr_originate.c:2079 Parsing global variables
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [call_timeout]=[20]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [originate_timeout]=[20]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [local_var_clobber]=[true]
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_ivr_originate.c:2526 Parsing session specific variables
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [ecallmgr_Authorizing-ID]=[22003c5c65e877bacc440e8da962ee5a]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [ecallmgr_Owner-ID]=[3210f77460b685eeaa93d04fd0871945]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [ecallmgr_Account-ID]=[5174fd7222418d0fb343cf577026d9d4]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [sdp_secure_savp_only]=[false]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [sip_invite_domain]=[test.com]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [presence_id]=[20...@test.com]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [absolute_codec_string]=[^^:PCMU:PCMA]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [leg_timeout]=[20]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [effective_callee_id_number]=[2002]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [effective_callee_id_name]=[2002]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [origination_callee_id_number]=[2002]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [origination_callee_id_name]=[2002]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [ecallmgr_Realm]=[test.com]
2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable [ecallmgr_Username]=[2002]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [NOTICE] switch_channel.c:1054 New Channel sofia/sipinterface_1/20...@24.13.173.136:5062 [152fb1fc-8673-11e4-9597-4be03abd148f]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] mod_sofia.c:4591 (sofia/sipinterface_1/20...@24.13.173.136:5062) State Change CS_NEW -> CS_INIT
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG] switch_ivr_originate.c:2820 sofia/sipinterface_1/20...@24.13.173.136:5062 Setting leg timeout to 20
2014-12-18 05:02:36.267891 [DEBUG] kazoo_event_stream.c:242 increased event stream buffer size to 4178
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@24.13.173.136:5062) Running State Change CS_INIT
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:510 (sofia/sipinterface_1/20...@24.13.173.136:5062) State INIT
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] mod_sofia.c:87 sofia/sipinterface_1/20...@24.13.173.136:5062 SOFIA INIT
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] sofia_glue.c:1197 sip:172.31.38.228:5060 Setting proxy route to sofia/sipinterface_1/20...@24.13.173.136:5062
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] sofia_glue.c:1226 sofia/sipinterface_1/20...@24.13.173.136:5062 sending invite version: 1.4.7  64bit
152fb1fc-8673-11e4-9597-4be03abd148f Local SDP:
152fb1fc-8673-11e4-9597-4be03abd148f v=0
152fb1fc-8673-11e4-9597-4be03abd148f o=FreeSWITCH 1418857238 1418857239 IN IP4 172.31.32.243
152fb1fc-8673-11e4-9597-4be03abd148f s=FreeSWITCH
152fb1fc-8673-11e4-9597-4be03abd148f c=IN IP4 172.31.32.243
152fb1fc-8673-11e4-9597-4be03abd148f t=0 0
152fb1fc-8673-11e4-9597-4be03abd148f m=audio 21718 RTP/AVP 0 8 101 13
152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:0 PCMU/8000
152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:8 PCMA/8000
152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:101 telephone-event/8000
152fb1fc-8673-11e4-9597-4be03abd148f a=fmtp:101 0-16
152fb1fc-8673-11e4-9597-4be03abd148f a=ptime:20
152fb1fc-8673-11e4-9597-4be03abd148f a=sendrecv
152fb1fc-8673-11e4-9597-4be03abd148f 
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/20...@24.13.173.136:5062 Standard INIT
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/20...@24.13.173.136:5062) State Change CS_INIT -> CS_ROUTING
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:510 (sofia/sipinterface_1/20...@24.13.173.136:5062) State INIT going to sleep
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@24.13.173.136:5062) Running State Change CS_ROUTING
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:526 (sofia/sipinterface_1/20...@24.13.173.136:5062) State ROUTING
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] mod_sofia.c:123 sofia/sipinterface_1/20...@24.13.173.136:5062 SOFIA ROUTING
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_ivr_originate.c:67 (sofia/sipinterface_1/20...@24.13.173.136:5062) State Change CS_ROUTING -> CS_CONSUME_MEDIA
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:526 (sofia/sipinterface_1/20...@24.13.173.136:5062) State ROUTING going to sleep
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@24.13.173.136:5062) Running State Change CS_CONSUME_MEDIA
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:545 (sofia/sipinterface_1/20...@24.13.173.136:5062) State CONSUME_MEDIA
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_state_machine.c:545 (sofia/sipinterface_1/20...@24.13.173.136:5062) State CONSUME_MEDIA going to sleep
send 1181 bytes to udp/[172.31.38.228]:5060 at 05:02:36.280913:
   ------------------------------------------------------------------------
   INVITE sip:20...@24.13.173.136:5062 SIP/2.0
   Via: SIP/2.0/UDP xx.172.103.138:11000;rport;branch=z9hG4bKmZ6N6H0mQSZ7N
   Route: <sip:172.31.38.228:5060>
   Max-Forwards: 49
   From: "2001" <sip:20...@test.com>;tag=2147tHjg7cemr
   Call-ID: 152fb1fc-8673-11e4-9597-4be03abd148f
   CSeq: 69103414 INVITE
   Contact: <sip:mod_...@xx.172.103.138:11000>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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: session
   Content-Length: 249
   X-AUTH-IP: 24.13.173.136
   X-FS-Support: update_display,send_info
   Remote-Party-ID: "2001" <sip:20...@test.com>;party=calling;screen=yes;privacy=off
   
   v=0
   o=FreeSWITCH 1418857238 1418857239 IN IP4 172.31.32.243
   s=FreeSWITCH
   c=IN IP4 172.31.32.243
   t=0 0
   m=audio 21718 RTP/AVP 0 8 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@24.13.173.136:5062 entering state [calling][0]
recv 325 bytes from udp/[172.31.38.228]:5060 at 05:02:36.283677:
   ------------------------------------------------------------------------
   SIP/2.0 100 Attempting to connect your call
   Via: SIP/2.0/UDP xx.172.103.138:11000;rport=11000;branch=z9hG4bKmZ6N6H0mQSZ7N;received=172.31.32.243
   From: "2001" <sip:20...@test.com>;tag=2147tHjg7cemr
   Call-ID: 152fb1fc-8673-11e4-9597-4be03abd148f
   CSeq: 69103414 INVITE
   Content-Length: 0
   
   ------------------------------------------------------------------------
2014-12-18 05:02:36.267891 [DEBUG] kazoo_node.c:1100 Sent erlang message to ecal...@ip-172-31-38-228.ec2.internal <3.4979.0>
2014-12-18 05:02:36.267891 [INFO] kazoo_node.c:625 exec: uuid_setvar_multi(152fb1fc-8673-11e4-9597-4be03abd148f ecallmgr_Channel-Authorized=true;ecallmgr_Account-ID=5174fd7222418d0fb343cf577026d9d4)
2014-12-18 05:02:36.467886 [DEBUG] kazoo_node.c:1100 Sent erlang message to ecal...@ip-172-31-38-228.ec2.internal <3.5021.0>
recv 626 bytes from udp/[172.31.38.228]:5060 at 05:02:36.666781:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP xx.172.103.138:11000;received=172.31.32.243;rport=11000;branch=z9hG4bKmZ6N6H0mQSZ7N
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2147tHjg7cemr>
   From: "2001" <sip:20...@test.com>;tag=2147tHjg7cemr
   To: <sip:20...@24.13.173.136:5062>;tag=1893664235
   Call-ID: 152fb1fc-8673-11e4-9597-4be03abd148f
   CSeq: 69103414 INVITE
   Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
   User-Agent: Yealink SIP-T20P 9.72.0.30
   Allow-Events: talk,hold,conference,refer,check-sync
   Content-Length: 0
   
   ------------------------------------------------------------------------
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.647887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.647887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.647887 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@24.13.173.136:5062 entering state [proceeding][180]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.647887 [NOTICE] sofia.c:6503 Ring-Ready sofia/sipinterface_1/20...@24.13.173.136:5062!
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.668240 [DEBUG] switch_channel.c:3272 (sofia/sipinterface_1/20...@24.13.173.136:5062) Callstate Change DOWN -> RINGING
2014-12-18 05:02:36.668240 [INFO] switch_ivr_originate.c:1192 Sending early media
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3528 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3528 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:2352 Set Codec sofia/sipinterface_1/20...@test.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/20...@test.com Original read codec set to PCMU:0
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:3732 No 2833 in SDP.  Disable 2833 dtmf and switch to INFO
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_media.c:4939 AUDIO RTP [sofia/sipinterface_1/20...@test.com] 172.31.32.243 port 30174 -> 24.13.173.136 port 11796 codec: 0 ms: 20
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_rtp.c:3383 Starting timer [soft] 160 bytes per 20ms
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [NOTICE] sofia_media.c:92 Pre-Answer sofia/sipinterface_1/20...@test.com!
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_channel.c:3394 (sofia/sipinterface_1/20...@test.com) Callstate Change RINGING -> EARLY
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] mod_sofia.c:2228 Ring SDP:
9411...@24.13.173.136 o=FreeSWITCH 1418848782 1418848783 IN IP4 172.31.32.243
9411...@24.13.173.136 c=IN IP4 172.31.32.243
9411...@24.13.173.136 m=audio 30174 RTP/AVP 0
9411...@24.13.173.136 a=rtpmap:0 PCMU/8000
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_session.c:907 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_ivr_originate.c:1249 Raw Codec Activation Success L16@8000hz 1 channel 20ms
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_codec.c:221 sofia/sipinterface_1/20...@test.com Push codec L16:70
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_ivr_originate.c:1317 Play Ringback Tone [%(2000,4000,440,480)]
send 1134 bytes to udp/[172.31.38.228]:5060 at 05:02:36.686834:
   ------------------------------------------------------------------------
   SIP/2.0 183 Session Progress
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bKfb11.54a11eb7.0;received=172.31.38.228
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1522596139
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464>
   From: "2001" <sip:20...@test.com>;tag=2022011464
   To: <sip:20...@test.com>;tag=1rBFSp1ca4Q1c
   Call-ID: 9411...@24.13.173.136
   CSeq: 2 INVITE
   Contact: <sip:20...@xx.172.103.138:11000;transport=udp>
   User-Agent: 2600hz
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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: session
   Content-Length: 166
   Remote-Party-ID: "2002" <sip:20...@test.com>;party=calling;privacy=off;screen=no
   
   v=0
   o=FreeSWITCH 1418848782 1418848783 IN IP4 172.31.32.243
   s=FreeSWITCH
   c=IN IP4 172.31.32.243
   t=0 0
   m=audio 30174 RTP/AVP 0
   a=rtpmap:0 PCMU/8000
   a=ptime:20
   ------------------------------------------------------------------------
9411...@24.13.173.136 2014-12-18 05:02:36.668240 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:36.707887 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@test.com entering state [early][183]
recv 316 bytes from udp/[172.31.38.228]:5060 at 05:02:37.191782:
   ------------------------------------------------------------------------
   OPTIONS sip:172.31.32.243:11000 SIP/2.0
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK1eba.750ea495.0
   To: sip:172.31.32.243:11000
   From: sip:sipc...@172.31.38.228;tag=27be82be2b1b1d1f52925a434ee69c40-48bf
   CSeq: 10 OPTIONS
   Max-Forwards: 70
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 706 bytes to udp/[172.31.38.228]:5060 at 05:02:37.192572:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK1eba.750ea495.0;received=172.31.38.228
   From: sip:sipc...@172.31.38.228;tag=27be82be2b1b1d1f52925a434ee69c40-48bf
   To: <sip:172.31.32.243:11000>;tag=3ay0vc3K4N46K
   CSeq: 10 OPTIONS
   Contact: <sip:xx.172.103.138:11000>
   User-Agent: 2600hz
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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-Length: 0
   
   ------------------------------------------------------------------------
recv 758 bytes from udp/[172.31.38.228]:5060 at 05:02:38.690185:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP xx.172.103.138:11000;received=172.31.32.243;rport=11000;branch=z9hG4bKmZ6N6H0mQSZ7N
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2147tHjg7cemr>
   From: "2001" <sip:20...@test.com>;tag=2147tHjg7cemr
   To: <sip:20...@24.13.173.136:5062>;tag=1893664235
   Call-ID: 152fb1fc-8673-11e4-9597-4be03abd148f
   CSeq: 69103414 INVITE
   Content-Type: application/sdp
   Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
   User-Agent: Yealink SIP-T20P 9.72.0.30
   Content-Length: 157
   
   v=0
   o=- 20081 20081 IN IP4 24.13.173.136
   s=SDP data
   c=IN IP4 24.13.173.136
   t=0 0
   m=audio 11788 RTP/AVP 0
   a=rtpmap:0 PCMU/8000
   a=sendrecv
   a=ptime:20
   ------------------------------------------------------------------------
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@24.13.173.136:5062 entering state [completing][200]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] sofia.c:6423 Remote SDP:
152fb1fc-8673-11e4-9597-4be03abd148f v=0
152fb1fc-8673-11e4-9597-4be03abd148f o=- 20081 20081 IN IP4 24.13.173.136
152fb1fc-8673-11e4-9597-4be03abd148f s=SDP data
152fb1fc-8673-11e4-9597-4be03abd148f c=IN IP4 24.13.173.136
152fb1fc-8673-11e4-9597-4be03abd148f t=0 0
152fb1fc-8673-11e4-9597-4be03abd148f m=audio 11788 RTP/AVP 0
152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:0 PCMU/8000
152fb1fc-8673-11e4-9597-4be03abd148f a=ptime:20
152fb1fc-8673-11e4-9597-4be03abd148f 
send 422 bytes to udp/[172.31.38.228]:5060 at 05:02:38.692286:
   ------------------------------------------------------------------------
   Via: SIP/2.0/UDP xx.172.103.138:11000;rport;branch=z9hG4bKN8Ze8cHrm2NtH
   Route: <sip:xx.172.197.98;lr=on;ftag=2147tHjg7cemr>
   Max-Forwards: 70
   From: "2001" <sip:20...@test.com>;tag=2147tHjg7cemr
   To: <sip:20...@24.13.173.136:5062>;tag=1893664235
   Call-ID: 152fb1fc-8673-11e4-9597-4be03abd148f
   CSeq: 69103414 ACK
   Contact: <sip:mod_...@xx.172.103.138:11000>
   Content-Length: 0
   
   ------------------------------------------------------------------------
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@24.13.173.136:5062 entering state [ready][200]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_media.c:3528 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_media.c:3474 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_media.c:2352 Set Codec sofia/sipinterface_1/20...@24.13.173.136:5062 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/20...@24.13.173.136:5062 Original read codec set to PCMU:0
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_media.c:3732 No 2833 in SDP.  Disable 2833 dtmf and switch to INFO
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_media.c:4939 AUDIO RTP [sofia/sipinterface_1/20...@24.13.173.136:5062] 172.31.32.243 port 21718 -> 24.13.173.136 port 11788 codec: 0 ms: 20
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_rtp.c:3383 Starting timer [soft] 160 bytes per 20ms
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [DEBUG] switch_channel.c:3630 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [NOTICE] sofia.c:7244 Channel [sofia/sipinterface_1/20...@24.13.173.136:5062] has been answered
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_channel.c:3684 (sofia/sipinterface_1/20...@24.13.173.136:5062) Callstate Change RINGING -> ACTIVE
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [DEBUG] switch_core_codec.c:246 sofia/sipinterface_1/20...@test.com Restore previous codec PCMU:0.
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [DEBUG] mod_sofia.c:785 Local SDP sofia/sipinterface_1/20...@test.com:
9411...@24.13.173.136 o=FreeSWITCH 1418848782 1418848784 IN IP4 172.31.32.243
9411...@24.13.173.136 c=IN IP4 172.31.32.243
9411...@24.13.173.136 m=audio 30174 RTP/AVP 0
9411...@24.13.173.136 a=rtpmap:0 PCMU/8000
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:907 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [NOTICE] switch_ivr_originate.c:3494 Channel [sofia/sipinterface_1/20...@test.com] has been answered
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [DEBUG] switch_channel.c:3684 (sofia/sipinterface_1/20...@test.com) Callstate Change EARLY -> ACTIVE
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [DEBUG] switch_ivr_originate.c:3552 Originate Resulted in Success: [sofia/sipinterface_1/20...@24.13.173.136:5062]
send 1095 bytes to udp/[172.31.38.228]:5060 at 05:02:38.705156:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bKfb11.54a11eb7.0;received=172.31.38.228
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1522596139
   Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464>
   From: "2001" <sip:20...@test.com>;tag=2022011464
   To: <sip:20...@test.com>;tag=1rBFSp1ca4Q1c
   Call-ID: 9411...@24.13.173.136
   CSeq: 2 INVITE
   Contact: <sip:20...@xx.172.103.138:11000;transport=udp>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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: session
   Content-Length: 166
   Remote-Party-ID: "2002" <sip:20...@test.com>;party=calling;privacy=off;screen=no
   
   v=0
   o=FreeSWITCH 1418848782 1418848783 IN IP4 172.31.32.243
   s=FreeSWITCH
   c=IN IP4 172.31.32.243
   t=0 0
   m=audio 30174 RTP/AVP 0
   a=rtpmap:0 PCMU/8000
   a=ptime:20
   ------------------------------------------------------------------------
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:907 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:907 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_ivr_bridge.c:1465 (sofia/sipinterface_1/20...@24.13.173.136:5062) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_session.c:1387 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_1/20...@24.13.173.136:5062) Running State Change CS_EXCHANGE_MEDIA
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] switch_core_state_machine.c:536 (sofia/sipinterface_1/20...@24.13.173.136:5062) State EXCHANGE_MEDIA
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.687886 [DEBUG] mod_sofia.c:599 SOFIA EXCHANGE_MEDIA
9411...@24.13.173.136 2014-12-18 05:02:38.708844 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.708844 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@test.com entering state [completed][200]
recv 737 bytes from udp/[xx.164.197.98]:5060 at 05:02:38.790178:
   ------------------------------------------------------------------------
   ACK sip:20...@xx.172.103.138:11000;transport=udp SIP/2.0
   Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bKcydzigwkX
   Via: SIP/2.0/UDP 24.13.173.136:61000;rport=61000;branch=z9hG4bK1653404120
   From: "2001" <sip:20...@test.com>;tag=2022011464
   To: <sip:20...@test.com>;tag=1rBFSp1ca4Q1c
   Call-ID: 9411...@24.13.173.136
   CSeq: 2 ACK
   Proxy-Authorization: Digest username="2001", realm="test.com", nonce="14ba98b8-8673-11e4-9587-4be03abd148f", uri="sip:20...@test.com:5060", response="d6ad5d56c648be2bd46e8ddcd4359db3", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000001
   Max-Forwards: 50
   Proxy-Require: 0
   User-Agent: Yealink SIP-T20P 9.72.0.30
   Content-Length: 0
   X-AUTH-IP: 24.13.173.136
   
   ------------------------------------------------------------------------
9411...@24.13.173.136 2014-12-18 05:02:38.787887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.787887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.787887 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.787887 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@test.com entering state [ready][200]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.787887 [DEBUG] switch_core_session.c:969 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.787887 [DEBUG] switch_core_session.c:969 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
send 951 bytes to udp/[172.31.38.228]:5060 at 05:02:38.815656:
   ------------------------------------------------------------------------
   UPDATE sip:20...@24.13.173.136:5062 SIP/2.0
   Via: SIP/2.0/UDP xx.172.103.138:11000;rport;branch=z9hG4bKpHS7971UHBcDD
   Route: <sip:xx.172.197.98;lr=on;ftag=2147tHjg7cemr>
   Max-Forwards: 70
   From: "2001" <sip:20...@test.com>;tag=2147tHjg7cemr
   To: <sip:20...@24.13.173.136:5062>;tag=1893664235
   Call-ID: 152fb1fc-8673-11e4-9597-4be03abd148f
   CSeq: 69103415 UPDATE
   Contact: <sip:mod_...@xx.172.103.138:11000>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: path, replaces
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 249
   P-Asserted-Identity: "2001" <sip:20...@172.31.32.243>
   
   v=0
   o=FreeSWITCH 1418857238 1418857239 IN IP4 172.31.32.243
   s=FreeSWITCH
   c=IN IP4 172.31.32.243
   t=0 0
   m=audio 21718 RTP/AVP 0 8 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.807890 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:38.807890 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@24.13.173.136:5062 entering state [calling][0]
send 852 bytes to udp/[xx.172.197.98]:5060 at 05:02:38.824161:
   ------------------------------------------------------------------------
   UPDATE sip:20...@24.13.173.136:61000 SIP/2.0
   Via: SIP/2.0/UDP xx.172.103.138:11000;rport;branch=z9hG4bKQtj0B3jZem2Zr
   Route: <sip:xx.172.197.98;lr=on;ftag=2022011464>
   Max-Forwards: 70
   From: <sip:20...@test.com>;tag=1rBFSp1ca4Q1c
   To: "2001" <sip:20...@test.com>;tag=2022011464
   Call-ID: 9411...@24.13.173.136
   CSeq: 69103415 UPDATE
   Contact: <sip:20...@xx.172.103.138:11000;transport=udp>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: path, replaces
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 166
   P-Asserted-Identity: "2002" <sip:20...@172.31.32.243>
   
   v=0
   o=FreeSWITCH 1418848782 1418848783 IN IP4 172.31.32.243
   s=FreeSWITCH
   c=IN IP4 172.31.32.243
   t=0 0
   m=audio 30174 RTP/AVP 0
   a=rtpmap:0 PCMU/8000
   a=ptime:20
   ------------------------------------------------------------------------
9411...@24.13.173.136 2014-12-18 05:02:38.807890 [DEBUG] switch_core_session.c:1052 Send signal sofia/sipinterface_1/20...@test.com [BREAK]
9411...@24.13.173.136 2014-12-18 05:02:38.807890 [DEBUG] sofia.c:6413 Channel sofia/sipinterface_1/20...@test.com entering state [calling][0]
recv 698 bytes from udp/[172.31.38.228]:5060 at 05:02:39.102075:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP xx.172.103.138:11000;received=172.31.32.243;rport=11000;branch=z9hG4bKpHS7971UHBcDD
   From: "2001" <sip:20...@test.com>;tag=2147tHjg7cemr
   To: <sip:20...@24.13.173.136:5062>;tag=1893664235
   Call-ID: 152fb1fc-8673-11e4-9597-4be03abd148f
   CSeq: 69103415 UPDATE
   Content-Type: application/sdp
   Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
   User-Agent: Yealink SIP-T20P 9.72.0.30
   Content-Length: 157
   
   v=0
   o=- 20081 20082 IN IP4 24.13.173.136
   s=SDP data
   c=IN IP4 24.13.173.136
   t=0 0
   m=audio 11788 RTP/AVP 0
   a=rtpmap:0 PCMU/8000
   a=sendrecv
   a=ptime:20
   ------------------------------------------------------------------------

Thanks,

Rajesh -Beaconnetx.com

James Aimonetti

unread,
Dec 18, 2014, 12:18:42 PM12/18/14
to 2600h...@googlegroups.com
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Maybe http://wiki.freeswitch.org/wiki/Amazon_EC2 will help you?
- --
James Aimonetti
Lead Systems Architect / Impressionable Scallywag
"I thought I fixed that"

2600Hz | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQEcBAEBAgAGBQJUkwxvAAoJENTKa+JPXCVgRWYH/jA9NL7T2hQSZVWR42jtHG27
tj/GhWCuVsj+yRrArW//z0YSbpc+Y20V4A2dEvQkVe9LxtWSPWVxXxQUrAyNkKM8
rOraXY2+lHzdEUtmh1mFholhF1DFrgL8lV8N+qDHu7fiw+/x2CisOmlzG+bhTC8y
a91Cx2ot+I1izN+uPUY9fiL+VNv/47Ej3dXkC43gid+xUSomi12CmPyN2Q4Ic/Th
oZ7iVlQysT+EkMTBNtZCdzI1NMSxwwkWN4mFUrweDIKZT8UiOhHPkBqSDfiJY3Xd
6Etpg4m3kWGuozKXafgrBPS73Vkv2VyauBN7Qrb7XJVa1KBtu2nvzLTN+TwCa8U=
=xICo
-----END PGP SIGNATURE-----

James Aimonetti

unread,
Dec 18, 2014, 12:21:39 PM12/18/14
to 2600h...@googlegroups.com
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

There's also a current thread on the FreeSWITCH users ML that may be
worth following/chiming in on (and probably others in the archive):

http://lists.freeswitch.org/pipermail/freeswitch-users/2014-December/109808.html
iQEcBAEBAgAGBQJUkw0eAAoJENTKa+JPXCVgw6QH/0ENYhpx0u0k6MrJ0cozl+0s
S8QEzxV1z1EUtjEJgak3XhRX+8k0yP6B631b4RBNCEDvec5Kc0jO2KMt+HFj2R/o
1m8xFIHuSEXUPFFvYPQPdURknWEd/atZMLc4TCUh9cQpjJePN8cBJfrtPwj1BuGu
ZJw3R0d4VP7iou1RPPuToUO8HEdaU5MRY0J+Sf2XcnImJBolPWHlNFSXx5LTiSGZ
y72K2SJK+iv50GmrpYipmbr0TK5vyO/+vRrrHVHkE4Ht6AsUM98G9LKPgYVuk9KL
KXoyafYrtZXEy+PTs7fdtcp8D5NZ3yf3LZXKxBqnyh/pglO4lES6+wSuy8UVg84=
=n3lv
-----END PGP SIGNATURE-----

rajesh,beaconnetx

unread,
Dec 18, 2014, 10:19:42 PM12/18/14
to 2600h...@googlegroups.com, ja...@2600hz.com
Hi James,

We have set Amazon EC2 public IP in Ext-RTP-IP in FS sip profile but FS still sends an internal IP in the SDP.
slide 18 mentions kamailio fixes nat/sdp and slide 21 says freeswitch has no local configuration.

Can you please confirm if Kamailio suppose to fix IP address in SDP? If yes, do we need to specify any configuration.

In kazoo-freeswitch-R15B-1.4.2-1.el6.x86_64, we see Public IP address in the SDP. Have you done any changes to FS load kazoo-freeswitch-R15B-1.4.7-4.el6.x86_64  ?


Thanks,

Rajesh

>> Node          : whistle_apps@ip-172-31-38-228.ec2.internal
>> Version : R15B03 Memory Usage  : 38.65MB Processes     : 1633
>> Ports : 33 Zone          : local Broker        :
>> amqp://guest:gu...@127.0.0.1:5672 WhApps        : callflow camper
>> cdr conference crossbar            fax hangups media_mgr
>> milliwatt           notify omnipresence pivot registrar
>> reorder stepswitch sysconf trunkstore
>
>> Node          : ecal...@ip-172-31-38-228.ec2.internal Version :
>> R15B03 Memory Usage  : 24.08MB Processes     : 996 Ports : 46
>> Zone          : local Broker        :
>> amqp://guest:gu...@127.0.0.1:5672 WhApps        : ecallmgr
>> Channels      : 0 Registrations : 1 Media Servers :
>> freeswitch@ip-172-31-32-243.ec2.internal
>
>
>
>
>> Freeswitch debug.log -
>> ------------------------------------------------------------------------
>
>>
>
> recv 931 bytes from udp/[172.31.38.228]:5060 at 05:02:35.505085:
>> ------------------------------------------------------------------------
>
>>
>
> INVITE sip:20...@test.com:5060 SIP/2.0
>> Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464> Via:
>> SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0
>> Via: SIP/2.0/UDP
>> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944 From:
>>  Call-ID: 9411...@24.13.173.136 CSeq: 1 INVITE Contact:
>> <sip:20...@24.13.173.136:61000> Content-Type: application/sdp
>> Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY,
>> REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
>> Max-Forwards: 50 User-Agent: Yealink SIP-T20P 9.72.0.30
>> Proxy-Require: 0 Supported: replaces Allow-Events:
>> talk,hold,conference,refer,check-sync Content-Length: 181
>> X-AUTH-IP: 24.13.173.136
>
>> v=0 o=- 20184 20184 IN IP4 24.13.173.136 s=SDP data c=IN IP4
>> 24.13.173.136 t=0 0 m=audio 11796 RTP/AVP 0 8 a=rtpmap:0
>> PCMU/8000 a=rtpmap:8 PCMA/8000 a=ptime:20 a=sendrecv
>> ------------------------------------------------------------------------
>
>>
>
> send 407 bytes to udp/[172.31.38.228]:5060 at 05:02:35.505452:
>> ------------------------------------------------------------------------
>
>>
>
> SIP/2.0 100 Trying
>> Via: SIP/2.0/UDP
>> xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0;received=172.31.38.228
>
>>
>
> Via: SIP/2.0/UDP
> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944
>> Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464> From:
>> From: "2001" <sip:...@test.com>;tag=2022011464 To:
>> <sip:...@test.com>;tag=0FjpQUg9cU1eH Call-ID:
>> 9411...@24.13.173.136 CSeq: 1 INVITE User-Agent: 2600hz
>> Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS,
>> MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH,
>> SUBSCRIBE Supported: 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 Proxy-Authenticate: Digest
>> realm="test.com", nonce="14ba98b8-8673-11e4-9587-4be03abd148f",
>> algorithm=MD5, qop="auth" Content-Length: 0
>
>> ------------------------------------------------------------------------
>
>>
>
> 9411...@24.13.173.136 2014-12-18 05:02:35.507926 [DEBUG]
>> switch_core_session.c:1052 Send signal
>> sofia/sipinterface_1/20...@test.com [BREAK] 2014-12-18
>> 05:02:35.507926 [DEBUG] sofia.c:2033 detaching session
>> 9411...@24.13.173.136 recv 281 bytes from
>> udp/[172.31.38.228]:5060 at 05:02:35.510682:
>> ------------------------------------------------------------------------
>
>>
>
> ACK sip:20...@test.com:5060 SIP/2.0
>> Via: SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0
>>  From: "2001" <sip:...@test.com>;tag=2022011464 To:
>> <sip:...@test.com>;tag=0FjpQUg9cU1eH Call-ID:
>> 9411...@24.13.173.136 CSeq: 1 ACK Max-Forwards: 50
>> Content-Length: 0
>
>> ------------------------------------------------------------------------
>
>>
>
> recv 1172 bytes from udp/[172.31.38.228]:5060 at 05:02:35.688752:
>> ------------------------------------------------------------------------
>
>>
>
> INVITE sip:20...@test.com:5060 SIP/2.0
>> Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464> Via:
>> SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bKfb11.54a11eb7.0
>> Via: SIP/2.0/UDP
>> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1522596139 From:
>>  ecallmgr@ip-172-31-38-228.ec2.internal <3.4391.0> 2014-12-18
>> 05:02:35.807887 [DEBUG] kazoo_fetch_agent.c:277 Received
>> dialplan XML (14d6f7f6-8673-11e4-9589-4be03abd148f) after 120ms:
>> <document type="freeswitch/xml"><section name="dialplan"
>> description="Route Park Response"><context
>> name="context_2"><extension name="park"><condition><action
>> application="log" data="NOTICE
>> log|${uuid}|ecallmgr@ip-172-31-38-228.ec2.internal won call
>> control"/><action application="export"
>> data="ecallmgr_Ecallmgr-Node=ecal...@ip-172-31-38-228.ec2.internal"/><condition
>>
>>
field="variable_ecallmgr_Bridge-ID" expression="^$"><action
>> application="export"
>> data="ecallmgr_Bridge-ID=${UUID}"/></condition><action
>> application="set" data="ringback=%(2000,4000,440,480)"/><action
>> application="set"
>> data="transfer_ringback=%(2000,4000,440,480)"/><action
>> application="park"/></condition></extension></context></section></document>
>
>>
>
> 9411...@24.13.173.136 Dialplan:
> sofia/sipinterface_1/20...@test.com
>> parsing [context_2->park] continue=false 9411...@24.13.173.136
>> |--- Dialplan: Processing recursive conditions level:1
>> [park_recur_1] require-nested=TRUE 9411...@24.13.173.136 |---
>> Dialplan: sofia/sipinterface_1/20...@test.com Regex (PASS)
>> [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/
>> break=on-false 9411...@24.13.173.136 |--- Dialplan:
>> sofia/sipinterface_1/20...@test.com Action
>> export(ecallmgr_Bridge-ID=${UUID}) 9411...@24.13.173.136
>> Dialplan: sofia/sipinterface_1/20...@test.com Absolute Condition
>> [park] 9411...@24.13.173.136 Dialplan:
>> sofia/sipinterface_1/20...@test.com Action log(NOTICE
>> log|${uuid}|ecallmgr@ip-172-31-38-228.ec2.internal won call
>> export(ecallmgr_Bridge-ID=941121...@24.13.173.136)
>> 9411...@24.13.173.136 2014-12-18 05:02:35.807887 [DEBUG]
>> switch_channel.c:1246 EXPORT (export_vars)
>> [ecallmgr_Bridge-ID]=[941121041...@24.13.173.136]
>>  ecallmgr@ip-172-31-38-228.ec2.internal <3.4943.0> 2014-12-18
>> 05:02:36.047887 [INFO] kazoo_node.c:625 exec:
>> uuid_setvar_multi(9411...@24.13.173.136
>> effective_caller_id_name=2001;effective_caller_id_number=2001;ecallmgr_Fetch-ID=14d6f7f6-8673-11e4-9589-4be03abd148f;ecallmgr_Username=2001;ecallmgr_Realm=test.com;ecallmgr_Account-ID=5174fd7222418d0fb343cf577026d9d4;ecallmgr_Authorizing-ID=02e0214ede86ab71c07ff8825f3eb389;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=9daa6151cc9dc382d48744fd3fb522e7;ecallmgr_Account-Realm=test.com;ecallmgr_Account-Name=test;presence_id=20...@test.com)
>
>>
>
> 2014-12-18 05:02:36.247887 [DEBUG] kazoo_node.c:1100 Sent erlang
> message to
>> ecal...@ip-172-31-38-228.ec2.internal <3.4979.0> 2014-12-18
>> 05:02:36.247887 [NOTICE] kazoo_node.c:302
>> log|9411...@24.13.173.136|building xferext extension: set
>> continue_on_fail=true 2014-12-18 05:02:36.247887 [NOTICE]
>> kazoo_node.c:302 log|9411...@24.13.173.136|building xferext
>> extension: export sip_redirect_context=context_2 2014-12-18
>> 05:02:36.247887 [NOTICE] kazoo_node.c:302
>> log|9411...@24.13.173.136|building xferext extension: export
>> ecallmgr_Inception=${ecallmgr_Inception} 2014-12-18
>> 05:02:36.247887 [NOTICE] kazoo_node.c:302
>> log|9411...@24.13.173.136|building xferext extension: bridge
>> {call_timeout=20,originate_timeout=20,local_var_clobber='true'}[ecallmgr_Authorizing-ID='22003c5c65e877bacc440e8da962ee5a',ecallmgr_Owner-ID='3210f77460b685eeaa93d04fd0871945',ecallmgr_Account-ID='5174fd7222418d0fb343cf577026d9d4',sdp_secure_savp_only='false',sip_invite_domain='test.com',presence_id='20...@test.com',absolute_codec_string='^^:PCMU:PCMA',leg_timeout='20',effective_callee_id_number='2002',effective_callee_id_name='2002',origination_callee_id_number='2002',origination_callee_id_name='2002',ecallmgr_Realm='test.com',ecallmgr_Username='2002']sofia/sipinterface_1/2002@24.13.173.136:5062;fs_path=sip:172.31.38.228:5060;lr;received='sip:24.13.173.136:5062'
>> bridge({call_timeout=20,originate_timeout=20,local_var_clobber=true}[ecallmgr_Authorizing-ID=22003c5c65e877bacc440e8da962ee5a,ecallmgr_Owner-ID=3210f77460b685eeaa93d04fd0871945,ecallmgr_Account-ID=5174fd7222418d0fb343cf577026d9d4,sdp_secure_savp_only=false,sip_invite_domain=test.com,presence_id=20...@test.com,absolute_codec_string=^^:PCMU:PCMA,leg_timeout=20,effective_callee_id_number=2002,effective_callee_id_name=2002,origination_callee_id_number=2002,origination_callee_id_name=2002,ecallmgr_Realm=test.com,ecallmgr_Username=2002]sofia/sipinterface_1/2002@24.13.173.136:5062;fs_path=sip:172.31.38.228:5060;lr;received=sip:24.13.173.136:5062)
>
>>
>
> 9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG]
>> switch_channel.c:1200 sofia/sipinterface_1/20...@test.com
>> EXPORTING[export_vars]
>> [ecallmgr_Bridge-ID]=[941121041...@24.13.173.136] to event
>> sofia/sipinterface_1/2002@24.13.173.136:5062
>> [152fb1fc-8673-11e4-9597-4be03abd148f]
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] mod_sofia.c:4591
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State Change
>> CS_NEW -> CS_INIT 152fb1fc-8673-11e4-9597-4be03abd148f
>> 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387
>> Send signal sofia/sipinterface_1/2002@24.13.173.136:5062 [BREAK]
>>  9411...@24.13.173.136 2014-12-18 05:02:36.267891 [DEBUG]
>> switch_ivr_originate.c:2820
>> sofia/sipinterface_1/2002@24.13.173.136:5062 Setting leg timeout
>> to 20 2014-12-18 05:02:36.267891 [DEBUG]
>> kazoo_event_stream.c:242 increased event stream buffer size to
>> 4178 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) Running State
>> Change CS_INIT 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:510
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State INIT
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] mod_sofia.c:87
>> sofia/sipinterface_1/2002@24.13.173.136:5062 SOFIA INIT
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] sofia_glue.c:1197 sip:172.31.38.228:5060 Setting proxy
>> route to sofia/sipinterface_1/2002@24.13.173.136:5062
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] sofia_glue.c:1226
>> sofia/sipinterface_1/2002@24.13.173.136:5062 sending invite
>> version: 1.4.7  64bit 152fb1fc-8673-11e4-9597-4be03abd148f Local
>> SDP: 152fb1fc-8673-11e4-9597-4be03abd148f v=0
>> 152fb1fc-8673-11e4-9597-4be03abd148f o=FreeSWITCH 1418857238
>> 1418857239 IN IP4 172.31.32.243
>> 152fb1fc-8673-11e4-9597-4be03abd148f s=FreeSWITCH
>> 152fb1fc-8673-11e4-9597-4be03abd148f c=IN IP4 172.31.32.243
>> 152fb1fc-8673-11e4-9597-4be03abd148f t=0 0
>> 152fb1fc-8673-11e4-9597-4be03abd148f m=audio 21718 RTP/AVP 0 8
>> 101 13 152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:0 PCMU/8000
>>  152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:8 PCMA/8000
>> 152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:101
>> telephone-event/8000 152fb1fc-8673-11e4-9597-4be03abd148f
>> a=fmtp:101 0-16 152fb1fc-8673-11e4-9597-4be03abd148f a=ptime:20
>> 152fb1fc-8673-11e4-9597-4be03abd148f a=sendrecv
>> 152fb1fc-8673-11e4-9597-4be03abd148f
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] switch_core_state_machine.c:40
>> sofia/sipinterface_1/2002@24.13.173.136:5062 Standard INIT
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] switch_core_state_machine.c:48
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State Change
>> CS_INIT -> CS_ROUTING 152fb1fc-8673-11e4-9597-4be03abd148f
>> 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387
>> Send signal sofia/sipinterface_1/2002@24.13.173.136:5062 [BREAK]
>>  152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] switch_core_state_machine.c:510
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State INIT going
>> to sleep 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) Running State
>> Change CS_ROUTING 152fb1fc-8673-11e4-9597-4be03abd148f
>> 2014-12-18 05:02:36.267891 [DEBUG]
>> switch_core_state_machine.c:526
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State ROUTING
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] mod_sofia.c:123
>> sofia/sipinterface_1/2002@24.13.173.136:5062 SOFIA ROUTING
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] switch_ivr_originate.c:67
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State Change
>> CS_ROUTING -> CS_CONSUME_MEDIA
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] switch_core_session.c:1387 Send signal
>> sofia/sipinterface_1/2002@24.13.173.136:5062 [BREAK]
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] switch_core_state_machine.c:526
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State ROUTING
>> going to sleep 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) Running State
>> Change CS_CONSUME_MEDIA 152fb1fc-8673-11e4-9597-4be03abd148f
>> 2014-12-18 05:02:36.267891 [DEBUG]
>> switch_core_state_machine.c:545
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State
>> CONSUME_MEDIA 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:545
>> (sofia/sipinterface_1/2002@24.13.173.136:5062) State
>> CONSUME_MEDIA going to sleep send 1181 bytes to
>> udp/[172.31.38.228]:5060 at 05:02:36.280913:
>> ------------------------------------------------------------------------
>
>>
>
> INVITE sip:20...@24.13.173.136:5062 SIP/2.0
>> Via: SIP/2.0/UDP
>> xx.172.103.138:11000;rport;branch=z9hG4bKmZ6N6H0mQSZ7N Route:
>> <sip:172.31.38.228:5060> Max-Forwards: 49 From: "2001"
>> <sip:...@test.com>;tag=2147tHjg7cemr To:
>> <sip:20...@24.13.173.136:5062> Call-ID:
>> 152fb1fc-8673-11e4-9597-4be03abd148f CSeq: 69103414 INVITE
>> Contact: <sip:mod_...@xx.172.103.138:11000> User-Agent: 2600hz
>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: 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: session
>> Content-Length: 249 X-AUTH-IP: 24.13.173.136 X-FS-Support:
>> update_display,send_info Remote-Party-ID: "2001"
>> <sip:...@test.com>;party=calling;screen=yes;privacy=off
>
>> v=0 o=FreeSWITCH 1418857238 1418857239 IN IP4 172.31.32.243
>> s=FreeSWITCH c=IN IP4 172.31.32.243 t=0 0 m=audio 21718 RTP/AVP 0
>> 8 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101
>> telephone-event/8000 a=fmtp:101 0-16 a=ptime:20
>> ------------------------------------------------------------------------
>
>>
>
> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
> [DEBUG]
>> switch_core_session.c:1052 Send signal
>> sofia/sipinterface_1/2002@24.13.173.136:5062 [BREAK]
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>> [DEBUG] sofia.c:6413 Channel
>> sofia/sipinterface_1/2002@24.13.173.136:5062 entering state
>> From: "2001" <sip:...@test.com>;tag=2147tHjg7cemr To:
>> <sip:20...@24.13.173.136:5062>;tag=1893664235 Call-ID:
>> 152fb1fc-8673-11e4-9597-4be03abd148f CSeq: 69103414 INVITE
>> Contact: <sip:20...@24.13.173.136:5062> Allow: INVITE, INFO,
>> PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE,
>> REFER, PUBLISH, UPDATE, MESSAGE User-Agent: Yealink SIP-T20P
>> 9.72.0.30 Allow-Events: talk,hold,conference,refer,check-sync
>> Content-Length: 0
>
>> ------------------------------------------------------------------------
>
>>
>
> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.647887
> [DEBUG]
>> switch_core_session.c:1052 Send signal
>> sofia/sipinterface_1/2002@24.13.173.136:5062 [BREAK]
>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.647887
>> [DEBU...

rajesh,beaconnetx

unread,
Dec 24, 2014, 2:31:43 PM12/24/14
to 2600h...@googlegroups.com, ja...@2600hz.com
Hi James,


Do you have any suggestions? Please confirm if Kamalio or Freeswitch suppose to perform RTP NAT function.

Rajesh
...

James Aimonetti

unread,
Dec 24, 2014, 3:11:49 PM12/24/14
to rajesh,beaconnetx, 2600h...@googlegroups.com
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Kamailio does any NAT translations, including SDP headers.

However, most FreeSWITCH servers configured in Kazoo go direct to the
endpoint and not back through Kamailio, especially for RTP. So if
FreeSWITCH is including local/internal IPs in the SDP, you need to
configure FreeSWITCH not to. If FreeSWITCH continues to put its
local/internal IP in the SDP after following
recommendations/instructions from the FreeSWITCH links earlier in this
thread, you've either not made the right changes, not restarted
sofia/FreeSWITCH for the changes to take effect, or you've uncovered a
bug in FreeSWITCH (not likely here). I would check with the FreeSWITCH
ML/IRC channel if you still can't get it working, as this is apart and
separate from Kazoo.

Hope you getting it working and share what the final resolution was!
>>>> Node : whistl...@ip-172-31-38-228.ec2.internal
>>>> Version : R15B03 Memory Usage : 38.65MB Processes : 1633
>>>> Ports : 33 Zone : local Broker :
>>>> amqp://guest:gu...@127.0.0.1:5672 WhApps : callflow
>>>> camper cdr conference crossbar fax hangups
>>>> media_mgr milliwatt notify omnipresence pivot
>>>> registrar reorder stepswitch sysconf trunkstore
>>>
>>>> Node : ecal...@ip-172-31-38-228.ec2.internal
>>>> Version : R15B03 Memory Usage : 24.08MB Processes : 996
>>>> Ports : 46 Zone : local Broker :
>>>> amqp://guest:gu...@127.0.0.1:5672 WhApps : ecallmgr
>>>> Channels : 0 Registrations : 1 Media Servers :
>>>> frees...@ip-172-31-32-243.ec2.internal
>>>
>>>
>>>
>>>
>>>> Freeswitch debug.log -
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> recv 931 bytes from udp/[172.31.38.228]:5060 at
>>> 05:02:35.505085:
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> INVITE sip:20...@test.com:5060 SIP/2.0
>>>> Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464> Via:
>>>> SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0
>>>> Via: SIP/2.0/UDP
>>>> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944
>>>> From: "2001" <sip:...@test.com <javascript:>>;tag=2022011464
>>>> To: <
>> sip:...@test.com <javascript:>>
>>>> Call-ID: 9411...@24.13.173.136 <javascript:> CSeq: 1 INVITE
>>>> Contact: <sip:20...@24.13.173.136:61000> Content-Type:
>>>> application/sdp Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL,
>>>> OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE,
>>>> MESSAGE Max-Forwards: 50 User-Agent: Yealink SIP-T20P
>>>> 9.72.0.30 Proxy-Require: 0 Supported: replaces Allow-Events:
>>>> talk,hold,conference,refer,check-sync Content-Length: 181
>>>> X-AUTH-IP: 24.13.173.136
>>>
>>>> v=0 o=- 20184 20184 IN IP4 24.13.173.136 s=SDP data c=IN IP4
>>>> 24.13.173.136 t=0 0 m=audio 11796 RTP/AVP 0 8 a=rtpmap:0
>>>> PCMU/8000 a=rtpmap:8 PCMA/8000 a=ptime:20 a=sendrecv
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> send 407 bytes to udp/[172.31.38.228]:5060 at 05:02:35.505452:
>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> SIP/2.0 100 Trying
>>>> Via: SIP/2.0/UDP
>>>> xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0;received=172.31.38.228
>>>>
>>>
>>>>
>>>
>>> Via: SIP/2.0/UDP
>>> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944
>>>> Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464> From:
>>>> "2001" <sip:...@test.com <javascript:>>;tag=2022011464 To:
>>>> <
>> sip:...@test.com <javascript:>>
>>>> Call-ID: 9411...@24.13.173.136 <javascript:> CSeq: 1 INVITE
>> User-Agent:
>>>> 2600hz Content-Length: 0
>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> 9411...@24.13.173.136 <javascript:> 2014-12-18 05:02:35.487887
>>> [NOTICE]
>>>> switch_channel.c:1054 New Channel
>>>> sofia/sipinterface_1/20...@test.com <javascript:> [
>> 9411...@24.13.173.136 <javascript:>]
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.487887 [DEBUG] switch_core_session.c:1052 Send
>>>> signal sofia/sipinterface_1/20...@test.com <javascript:>
>>>> [BREAK] 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.487887 [DEBUG] switch_core_session.c:1052 Send
>>>> signal sofia/sipinterface_1/20...@test.com <javascript:>
>>>> [BREAK] 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.507926 [DEBUG] switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) Running
>>>> State
>> Change CS_NEW
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.507926
>> [DEBUG]
>>>> sofia.c:8703 sofia/sipinterface_1/20...@test.com
>>>> <javascript:>
>> receiving invite
>>>> from 172.31.38.228:5060 version: 1.4.7 64bit 2014-12-18
>>>> 05:02:35.507926 [DEBUG] sofia.c:8825 1 acls to check for
>>>> proxy 2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8830
>>>> checking 172.31.38.228 against acl authoritative 2014-12-18
>>>> 05:02:35.507926 [DEBUG] sofia.c:8870 IP 172.31.38.228
>>>> Rejected by acl "authoritative". Falling back to Digest auth.
>>>> 2014-12-18 05:02:35.507926 [DEBUG] sofia_reg.c:3345 sofia
>>>> pre-register disabled...@24.13.173.136 <javascript:>
>>>> 2014-12-18 05:02:35.507926 [DEBUG]
>>>> switch_core_state_machine.c:489
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State NEW
>>>> send 842
>> bytes to
>>>> udp/[172.31.38.228]:5060 at 05:02:35.509803:
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> SIP/2.0 407 Proxy Authentication Required
>>>> Via: SIP/2.0/UDP
>>>> xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0;received=172.31.38.228
>>>>
>>>
>>>>
>>>
>>> Via: SIP/2.0/UDP
>>> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1822185944
>>>> From: "2001" <sip:...@test.com <javascript:>>;tag=2022011464
>>>> To: <sip:...@test.com <javascript:>>;tag=0FjpQUg9cU1eH
>>>> Call-ID: 9411...@24.13.173.136 <javascript:> CSeq: 1 INVITE
>>>> User-Agent: 2600hz Accept: application/sdp Allow: INVITE,
>>>> ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER,
>>>> REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: 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 Proxy-Authenticate: Digest realm="test.com",
>>>> nonce="14ba98b8-8673-11e4-9587-4be03abd148f", algorithm=MD5,
>>>> qop="auth" Content-Length: 0
>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> 9411...@24.13.173.136 <javascript:> 2014-12-18 05:02:35.507926
>>> [DEBUG]
>>>> switch_core_session.c:1052 Send signal
>>>> sofia/sipinterface_1/20...@test.com <javascript:> [BREAK]
>>>> 2014-12-18 05:02:35.507926 [DEBUG] sofia.c:2033 detaching
>>>> session 9411...@24.13.173.136 <javascript:> recv 281 bytes
>>>> from udp/[172.31.38.228]:5060 at 05:02:35.510682:
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> ACK sip:20...@test.com:5060 SIP/2.0
>>>> Via: SIP/2.0/UDP
>>>> xx.172.197.98:5060;branch=z9hG4bK2c11.21482cb5.0 From: "2001"
>>>> <sip:...@test.com <javascript:>>;tag=2022011464 To:
>>>> <sip:...@test.com <javascript:>>;tag=0FjpQUg9cU1eH Call-ID:
>>>> 9411...@24.13.173.136 <javascript:> CSeq: 1 ACK Max-Forwards:
>>>> 50 Content-Length: 0
>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> recv 1172 bytes from udp/[172.31.38.228]:5060 at
>>> 05:02:35.688752:
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> INVITE sip:20...@test.com:5060 SIP/2.0
>>>> Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464> Via:
>>>> SIP/2.0/UDP xx.172.197.98:5060;branch=z9hG4bKfb11.54a11eb7.0
>>>> Via: SIP/2.0/UDP
>>>> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1522596139
>>>> From: "2001" <sip:...@test.com <javascript:>>;tag=2022011464
>>>> To: <
>> sip:...@test.com <javascript:>>
>>>> Call-ID: 9411...@24.13.173.136 <javascript:> CSeq: 2 INVITE
>>>> Contact: <sip:20...@24.13.173.136:61000> Proxy-Authorization:
>>>> Digest username="2001", realm="test.com",
>>>> nonce="14ba98b8-8673-11e4-9587-4be03abd148f",
>>>> uri="sip:20...@test.com:5060",
>>>> response="d6ad5d56c648be2bd46e8ddcd4359db3", algorithm=MD5,
>>>> cnonce="0a4f113b", qop=auth, nc=00000001 Content-Type:
>>>> application/sdp Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL,
>>>> OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH,
>>>> UPDATE, MESSAGE Max-Forwards: 50 User-Agent: Yealink SIP-T20P
>>>> 9.72.0.30 Proxy-Require: 0 Supported: replaces Allow-Events:
>>>> talk,hold,conference,refer,check-sync Content-Length: 181
>>>> X-AUTH-IP: 24.13.173.136
>>>
>>>> v=0 o=- 20184 20184 IN IP4 24.13.173.136 s=SDP data c=IN IP4
>>>> 24.13.173.136 t=0 0 m=audio 11796 RTP/AVP 0 8 a=rtpmap:0
>>>> PCMU/8000 a=rtpmap:8 PCMA/8000 a=ptime:20 a=sendrecv
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> send 407 bytes to udp/[172.31.38.228]:5060 at 05:02:35.689006:
>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> SIP/2.0 100 Trying
>>>> Via: SIP/2.0/UDP
>>>> xx.172.197.98:5060;branch=z9hG4bKfb11.54a11eb7.0;received=172.31.38.228
>>>>
>>>
>>>>
>>>
>>> Via: SIP/2.0/UDP
>>> 24.13.173.136:61000;rport=61000;branch=z9hG4bK1522596139
>>>> Record-Route: <sip:xx.172.197.98;lr=on;ftag=2022011464> From:
>>>> "2001" <sip:...@test.com <javascript:>>;tag=2022011464 To:
>>>> <
>> sip:...@test.com <javascript:>>
>>>> Call-ID: 9411...@24.13.173.136 <javascript:> CSeq: 2 INVITE
>> User-Agent:
>>>> 2600hz Content-Length: 0
>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> 2014-12-18 05:02:35.687887 [DEBUG] sofia.c:2138 Re-attaching to
>>> session
>>>> 9411...@24.13.173.136 <javascript:> 9411...@24.13.173.136
>>>> <javascript:>
>> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_session.c:1052 Send
>>>> signal sofia/sipinterface_1/20...@test.com <javascript:>
>>>> [BREAK] 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_session.c:1052 Send
>>>> signal sofia/sipinterface_1/20...@test.com <javascript:>
>>>> [BREAK] 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] sofia.c:8703
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> receiving invite
>>>> from 172.31.38.228:5060 version: 1.4.7 64bit 2014-12-18
>>>> 05:02:35.687887 [DEBUG] sofia.c:8825 1 acls to check for
>>>> proxy 2014-12-18 05:02:35.687887 [DEBUG] sofia.c:8830
>>>> checking 172.31.38.228 against acl authoritative 2014-12-18
>>>> 05:02:35.687887 [DEBUG] sofia.c:8870 IP 172.31.38.228
>>>> Rejected by acl "authoritative". Falling back to Digest auth.
>>>> 2014-12-18 05:02:35.687887 [DEBUG] switch_xml.c:2009 Cache
>>>> Info - Time Now : 1418878955 - Expires : 1418882489
>>>> 2014-12-18 05:02:35.687887 [DEBUG] switch_xml.c:2015
>>>> 20...@test.com <javascript:> fetched from
>> cache
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] sofia.c:6413 Channel
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> entering
>>>> state [received][100] 9411...@24.13.173.136 <javascript:>
>>>> 2014-12-18 05:02:35.687887 [DEBUG] sofia.c:6423 Remote SDP:
>>>> 9411...@24.13.173.136 <javascript:> v=0 9411...@24.13.173.136
>>>>
>> <javascript:> o=- 20184
>>>> 20184 IN IP4 24.13.173.136 9411...@24.13.173.136
>>>> <javascript:> s=SDP
>> data
>>>> 9411...@24.13.173.136 <javascript:> c=IN IP4 24.13.173.136
>>>> 9411...@24.13.173.136 <javascript:> t=0 0
>>>> 9411...@24.13.173.136
>> <javascript:> m=audio
>>>> 11796 RTP/AVP 0 8 9411...@24.13.173.136 <javascript:>
>>>> a=rtpmap:0
>> PCMU/8000
>>>> 9411...@24.13.173.136 <javascript:> a=rtpmap:8 PCMA/8000
>>>> 9411...@24.13.173.136 <javascript:> a=ptime:20
>>>> 9411...@24.13.173.136
>> <javascript:>
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] sofia.c:6678
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>> Change
>>>> CS_NEW -> CS_INIT 9411...@24.13.173.136 <javascript:>
>>>> 2014-12-18 05:02:35.687887 [DEBUG] switch_core_session.c:1387
>>>> Send signal sofia/sipinterface_1/20...@test.com <javascript:>
>>>> [BREAK] 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) Running
>>>> State
>> Change CS_INIT
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887
>> [DEBUG]
>>>> switch_core_state_machine.c:510
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> INIT 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] mod_sofia.c:87
>>>> sofia/sipinterface_1/20...@test.com <javascript:> SOFIA
>> INIT
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_state_machine.c:40
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Standard
>>>> INIT 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_state_machine.c:48
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> Change
>> CS_INIT ->
>>>> CS_ROUTING 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:35.687887
>>>> [DEBUG] switch_core_session.c:1387 Send signal
>>>> sofia/sipinterface_1/20...@test.com <javascript:> [BREAK]
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_state_machine.c:510
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> INIT going
>> to sleep
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) Running
>>>> State
>> Change
>>>> CS_ROUTING 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:35.687887
>>>> [DEBUG] switch_channel.c:2179
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) Callstate
>>>> Change
>> DOWN ->
>>>> RINGING 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] switch_core_state_machine.c:526
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> ROUTING 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [DEBUG] mod_sofia.c:123
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> SOFIA ROUTING
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887
>> [DEBUG]
>>>> switch_core_state_machine.c:164
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Standard
>>>> ROUTING 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.687887 [INFO] mod_dialplan_xml.c:558 Processing 2001
>>>> <2001>->2002 in context context_2 2014-12-18 05:02:35.687887
>>>> [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request
>>>> (14d6f7f6-8673-11e4-9589-4be03abd148f) to
>>>> ecal...@ip-172-31-38-228.ec2.internal <3.4391.0> 2014-12-18
>>>> 05:02:35.807887 [DEBUG] kazoo_node.c:1100 Sent erlang
>>>> message to ecal...@ip-172-31-38-228.ec2.internal <3.4391.0>
>>>> 2014-12-18 05:02:35.807887 [DEBUG] kazoo_fetch_agent.c:277
>>>> Received dialplan XML (14d6f7f6-8673-11e4-9589-4be03abd148f)
>>>> after 120ms: <document type="freeswitch/xml"><section
>>>> name="dialplan" description="Route Park Response"><context
>>>> name="context_2"><extension name="park"><condition><action
>>>> application="log" data="NOTICE
>>>> log|${uuid}|ecal...@ip-172-31-38-228.ec2.internal won call
>>>> control"/><action application="export"
>>>>
>> data="ecallmgr_Ecallmgr-Node=ecal...@ip-172-31-38-228.ec2.internal"/><condition
>>
>>
>>>>
>>>>
>> field="variable_ecallmgr_Bridge-ID" expression="^$"><action
>>>> application="export"
>>>> data="ecallmgr_Bridge-ID=${UUID}"/></condition><action
>>>> application="set"
>>>> data="ringback=%(2000,4000,440,480)"/><action
>>>> application="set"
>>>> data="transfer_ringback=%(2000,4000,440,480)"/><action
>>>>
>> application="park"/></condition></extension></context></section></document>
>>
>>>
>>>>
>>>
>>> 9411...@24.13.173.136 <javascript:> Dialplan:
>>> sofia/sipinterface_1/20...@test.com <javascript:>
>>>> parsing [context_2->park] continue=false
>>>> 9411...@24.13.173.136
>> <javascript:>
>>>> |--- Dialplan: Processing recursive conditions level:1
>>>> [park_recur_1] require-nested=TRUE 9411...@24.13.173.136
>>>> <javascript:>
>> |---
>>>> Dialplan: sofia/sipinterface_1/20...@test.com <javascript:>
>>>> Regex
>> (PASS)
>>>> [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/
>>>> break=on-false 9411...@24.13.173.136 <javascript:> |---
>>>> Dialplan: sofia/sipinterface_1/20...@test.com <javascript:>
>>>> Action export(ecallmgr_Bridge-ID=${UUID})
>>>> 9411...@24.13.173.136 <javascript:> Dialplan:
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Absolute
>> Condition
>>>> [park] 9411...@24.13.173.136 <javascript:> Dialplan:
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Action
>>>> log(NOTICE log|${uuid}|ecal...@ip-172-31-38-228.ec2.internal
>>>> won call control) 9411...@24.13.173.136 <javascript:>
>>>> Dialplan: sofia/sipinterface_1/20...@test.com <javascript:>
>>>> Action
>>>> export(ecallmgr_Ecallmgr-Node=ecal...@ip-172-31-38-228.ec2.internal)
>>>>
>>>
>>>>
>>>
>>> 9411...@24.13.173.136 <javascript:> Dialplan:
>>> sofia/sipinterface_1/20...@test.com <javascript:> Action
>>>> set(ringback=%(2000,4000,440,480)) 9411...@24.13.173.136
>>>> <javascript:> Dialplan: sofia/sipinterface_1/20...@test.com
>>>> <javascript:> Action
>>>> set(transfer_ringback=%(2000,4000,440,480))
>>>> 9411...@24.13.173.136 <javascript:> Dialplan:
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Action
>>>> park() 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.807887 [DEBUG] switch_core_state_machine.c:214
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> Change
>> CS_ROUTING ->
>>>> CS_EXECUTE 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:35.807887
>>>> [DEBUG] switch_core_session.c:1387 Send signal
>>>> sofia/sipinterface_1/20...@test.com <javascript:> [BREAK]
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.807887 [DEBUG] switch_core_state_machine.c:526
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> ROUTING
>> going to sleep
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.807887
>> [DEBUG]
>>>> switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) Running
>>>> State
>> Change
>>>> CS_EXECUTE 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:35.807887
>>>> [DEBUG] switch_core_state_machine.c:533
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> EXECUTE 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.807887 [DEBUG] mod_sofia.c:178
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> SOFIA EXECUTE
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.807887
>> [DEBUG]
>>>> switch_core_state_machine.c:256
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Standard
>>>> EXECUTE 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>>>> export(ecallmgr_Bridge-ID=9411...@24.13.173.136
>>>> <javascript:>) 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.807887 [DEBUG] switch_channel.c:1246 EXPORT
>>>> (export_vars) [ecallmgr_Bridge-ID]=[9411...@24.13.173.136
>>>> <javascript:>] 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:> log(NOTICE
>>>> log|9411...@24.13.173.136
>>>> <javascript:>|ecal...@ip-172-31-38-228.ec2.internal
>>
>>>>
>>>>
>> won call control) 9411...@24.13.173.136 <javascript:> 2014-12-18
>>
>>>> 05:02:35.807887 [NOTICE] mod_dptools.c:1667
>>>> log|9411...@24.13.173.136
>>>> <javascript:>|ecal...@ip-172-31-38-228.ec2.internal
>>
>>>>
>>>>
>> won call control 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>>>> export(ecallmgr_Ecallmgr-Node=ecal...@ip-172-31-38-228.ec2.internal)
>>>>
>>>
>>>>
>>>
>>> 9411...@24.13.173.136 <javascript:> 2014-12-18 05:02:35.807887
>>> [DEBUG]
>>>> switch_channel.c:1246 EXPORT (export_vars)
>>>> [ecallmgr_Ecallmgr-Node]=[ecal...@ip-172-31-38-228.ec2.internal]
>>>> 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>>>> set(ringback=%(2000,4000,440,480)) 9411...@24.13.173.136
>>>> <javascript:> 2014-12-18 05:02:35.807887 [DEBUG]
>>>> mod_dptools.c:1435 sofia/sipinterface_1/20...@test.com
>>>> <javascript:> SET [ringback]=[%(2000,4000,440,480)]
>>>> 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>>>> set(transfer_ringback=%(2000,4000,440,480))
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:35.807887 [DEBUG] mod_dptools.c:1435
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> SET
>>>> [transfer_ringback]=[%(2000,4000,440,480)]
>>>> 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:> park()
>>>> 2014-12-18 05:02:36.007891 [DEBUG] kazoo_node.c:1100 Sent
>>>> erlang message to ecal...@ip-172-31-38-228.ec2.internal
>>>> <3.4943.0> 2014-12-18 05:02:36.047887 [INFO] kazoo_node.c:625
>>>> exec: uuid_setvar_multi(9411...@24.13.173.136 <javascript:>
>>>>
>> effective_caller_id_name=2001;effective_caller_id_number=2001;ecallmgr_Fetch-ID=14d6f7f6-8673-11e4-9589-4be03abd148f;ecallmgr_Username=2001;ecallmgr_Realm=
>>
>>
test.com
>> ;ecallmgr_Account-ID=5174fd7222418d0fb343cf577026d9d4;ecallmgr_Authorizing-ID=02e0214ede86ab71c07ff8825f3eb389;ecallmgr_Authorizing-Type=device;ecallmgr_Owner-ID=9daa6151cc9dc382d48744fd3fb522e7;ecallmgr_Account-Realm=
>>
>>
test.com;ecallmgr_Account-Name=test;presence_id=20...@test.com
>> <javascript:>)
>>>
>>>>
>>>
>>> 2014-12-18 05:02:36.247887 [DEBUG] kazoo_node.c:1100 Sent
>>> erlang message to
>>>> ecal...@ip-172-31-38-228.ec2.internal <3.4979.0> 2014-12-18
>>>> 05:02:36.247887 [NOTICE] kazoo_node.c:302
>>>> log|9411...@24.13.173.136 <javascript:>|building xferext
>>>> extension:
>> set
>>>> continue_on_fail=true 2014-12-18 05:02:36.247887 [NOTICE]
>>>> kazoo_node.c:302 log|9411...@24.13.173.136
>>>> <javascript:>|building
>> xferext
>>>> extension: export sip_redirect_context=context_2 2014-12-18
>>>> 05:02:36.247887 [NOTICE] kazoo_node.c:302
>>>> log|9411...@24.13.173.136 <javascript:>|building xferext
>>>> extension:
>> export
>>>> ecallmgr_Inception=${ecallmgr_Inception} 2014-12-18
>>>> 05:02:36.247887 [NOTICE] kazoo_node.c:302
>>>> log|9411...@24.13.173.136 <javascript:>|building xferext
>>>> extension:
>> bridge
>>>>
>> {call_timeout=20,originate_timeout=20,local_var_clobber='true'}[ecallmgr_Authorizing-ID='22003c5c65e877bacc440e8da962ee5a',ecallmgr_Owner-ID='3210f77460b685eeaa93d04fd0871945',ecallmgr_Account-ID='5174fd7222418d0fb343cf577026d9d4',sdp_secure_savp_only='false',sip_invite_domain='
>>
>>
test.com',presence_id='20...@test.com <javascript:>
>> ',absolute_codec_string='^^:PCMU:PCMA',leg_timeout='20',effective_callee_id_number='2002',effective_callee_id_name='2002',origination_callee_id_number='2002',origination_callee_id_name='2002',ecallmgr_Realm='
>>
>>
test.com
>> ',ecallmgr_Username='2002']sofia/sipinterface_1/20...@24.13.173.136:5062;fs_path=sip:172.31.38.228:5060;lr;received='sip:
>>
>>
24.13.173.136:5062'
>>>
>>>>
>>>
>>> 2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302
>>>> log|9411...@24.13.173.136 <javascript:>|building xferext
>>>> extension:
>> event
>>>>
>> Event-Name=CUSTOM,Event-Subclass=whistle::masquerade,whistle_event_name=CHANNEL_EXECUTE_COMPLETE,whistle_application_name=bridge
>>
>>
>>>
>>>>
>>>
>>> 2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:302
>>>> log|9411...@24.13.173.136 <javascript:>|building xferext
>>>> extension:
>> park
>>>> 2014-12-18 05:02:36.247887 [NOTICE] kazoo_node.c:305
>>>> log|9411...@24.13.173.136 <javascript:>|transfered call to
>>>> xferext
>> extension
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.247887
>> [DEBUG]
>>>> switch_core_session.c:1187 Send signal
>>>> sofia/sipinterface_1/20...@test.com <javascript:> [BREAK]
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_channel.c:3098
>>>> (sofia/sipinterface_1/20...@test.com
>> <javascript:>) State
>>>> Change CS_EXECUTE -> CS_ROUTING 9411...@24.13.173.136
>>>> <javascript:> 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_core_session.c:1387 Send signal
>>>> sofia/sipinterface_1/20...@test.com <javascript:> [BREAK]
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:533
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> EXECUTE
>> going to sleep
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891
>> [DEBUG]
>>>> switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) Running
>>>> State
>> Change
>>>> CS_ROUTING 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:36.267891
>>>> [DEBUG] switch_core_state_machine.c:526
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> ROUTING 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] mod_sofia.c:123
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> SOFIA ROUTING
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891
>> [DEBUG]
>>>> switch_core_state_machine.c:164
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Standard
>>>> ROUTING 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:184
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> Change
>> CS_ROUTING ->
>>>> CS_EXECUTE 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:36.267891
>>>> [DEBUG] switch_core_session.c:1387 Send signal
>>>> sofia/sipinterface_1/20...@test.com <javascript:> [BREAK]
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:526
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> ROUTING
>> going to sleep
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891
>> [DEBUG]
>>>> switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) Running
>>>> State
>> Change
>>>> CS_EXECUTE 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:36.267891
>>>> [DEBUG] switch_core_state_machine.c:533
>>>> (sofia/sipinterface_1/20...@test.com <javascript:>) State
>>>> EXECUTE 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] mod_sofia.c:178
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> SOFIA EXECUTE
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891
>> [DEBUG]
>>>> switch_core_state_machine.c:256
>>>> sofia/sipinterface_1/20...@test.com <javascript:> Standard
>>>> EXECUTE 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> set(continue_on_fail=true)
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] mod_dptools.c:1435
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> SET
>>>> [continue_on_fail]=[true] 9411...@24.13.173.136 <javascript:>
>>>> EXECUTE sofia/sipinterface_1/20...@test.com <javascript:>
>>>> export(sip_redirect_context=context_2) 9411...@24.13.173.136
>>>>
>> <javascript:>
>>>> 2014-12-18 05:02:36.267891 [DEBUG] switch_channel.c:1246
>>>> EXPORT (export_vars) [sip_redirect_context]=[context_2]
>>>> 9411...@24.13.173.136 <javascript:> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>> export(ecallmgr_Inception=)
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_channel.c:1246 EXPORT
>>>> (export_vars) [ecallmgr_Inception]=[UNDEF]
>>>> 9411...@24.13.173.136 <javascript:>
>> EXECUTE
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>>>>
>> bridge({call_timeout=20,originate_timeout=20,local_var_clobber=true}[ecallmgr_Authorizing-ID=22003c5c65e877bacc440e8da962ee5a,ecallmgr_Owner-ID=3210f77460b685eeaa93d04fd0871945,ecallmgr_Account-ID=5174fd7222418d0fb343cf577026d9d4,sdp_secure_savp_only=false,sip_invite_domain=
>>
>>
test.com,presence_id=20...@test.com <javascript:>
>> ,absolute_codec_string=^^:PCMU:PCMA,leg_timeout=20,effective_callee_id_number=2002,effective_callee_id_name=2002,origination_callee_id_number=2002,origination_callee_id_name=2002,ecallmgr_Realm=
>>
>>
test.com
>> ,ecallmgr_Username=2002]sofia/sipinterface_1/20...@24.13.173.136:5062;fs_path=sip:172.31.38.228:5060;lr;received=sip:
>>
>>
24.13.173.136:5062)
>>>
>>>>
>>>
>>> 9411...@24.13.173.136 <javascript:> 2014-12-18 05:02:36.267891
>>> [DEBUG]
>>>> switch_channel.c:1200 sofia/sipinterface_1/20...@test.com
>>>> <javascript:> EXPORTING[export_vars]
>>>> [ecallmgr_Bridge-ID]=[9411...@24.13.173.136 <javascript:>]
>>>> to event 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_channel.c:1200
>>>> sofia/sipinterface_1/20...@test.com <javascript:>
>>>> EXPORTING[export_vars]
>>>> [ecallmgr_Ecallmgr-Node]=[ecal...@ip-172-31-38-228.ec2.internal]
>>>>
>>>>
>>>>
>> to event 9411...@24.13.173.136 <javascript:> 2014-12-18
>> 05:02:36.267891 [DEBUG]
>>>> switch_channel.c:1200 sofia/sipinterface_1/20...@test.com
>>>> <javascript:> EXPORTING[export_vars]
>>>> [sip_redirect_context]=[context_2] to event
>>>> 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891
>> [DEBUG]
>>>> switch_ivr_originate.c:2079 Parsing global variables
>>>> 2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688
>>>> Parsing variable [call_timeout]=[20] 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable
>>>> [originate_timeout]=[20] 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_event.c:1688 Parsing variable
>>>> [local_var_clobber]=[true] 9411...@24.13.173.136
>>>> <javascript:> 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_ivr_originate.c:2526 Parsing session specific
>>>> variables 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_event.c:1688 Parsing variable
>>>> [ecallmgr_Authorizing-ID]=[22003c5c65e877bacc440e8da962ee5a]
>>>> 2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688
>>>> Parsing variable
>>>> [ecallmgr_Owner-ID]=[3210f77460b685eeaa93d04fd0871945]
>>>> 2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688
>>>> Parsing variable
>>>> [ecallmgr_Account-ID]=[5174fd7222418d0fb343cf577026d9d4]
>>>> 2014-12-18 05:02:36.267891 [DEBUG] switch_event.c:1688
>>>> Parsing variable [sdp_secure_savp_only]=[false] 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable
>>>> [sip_invite_domain]=[test.com] 2014-12-18 05:02:36.267891
>>>> [DEBUG] switch_event.c:1688 Parsing variable
>>>> [presence_id]=[20...@test.com <javascript:>] 2014-12-18
>> 05:02:36.267891 [DEBUG]
>>>> switch_event.c:1688 Parsing variable
>>>> [absolute_codec_string]=[^^:PCMU:PCMA] 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable
>>>> [leg_timeout]=[20] 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_event.c:1688 Parsing variable
>>>> [effective_callee_id_number]=[2002] 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable
>>>> [effective_callee_id_name]=[2002] 2014-12-18 05:02:36.267891
>>>> [DEBUG] switch_event.c:1688 Parsing variable
>>>> [origination_callee_id_number]=[2002] 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable
>>>> [origination_callee_id_name]=[2002] 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_event.c:1688 Parsing variable
>>>> [ecallmgr_Realm]=[test.com] 2014-12-18 05:02:36.267891
>>>> [DEBUG] switch_event.c:1688 Parsing variable
>>>> [ecallmgr_Username]=[2002]
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [NOTICE] switch_channel.c:1054 New Channel
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062
>>>> [152fb1fc-8673-11e4-9597-4be03abd148f]
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] mod_sofia.c:4591
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State Change
>>>> CS_NEW -> CS_INIT 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387
>>>> Send signal sofia/sipinterface_1/20...@24.13.173.136:5062
>>>> [BREAK] 9411...@24.13.173.136 <javascript:> 2014-12-18
>>>> 05:02:36.267891
>> [DEBUG]
>>>> switch_ivr_originate.c:2820
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 Setting leg
>>>> timeout to 20 2014-12-18 05:02:36.267891 [DEBUG]
>>>> kazoo_event_stream.c:242 increased event stream buffer size
>>>> to 4178 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) Running State
>>>> Change CS_INIT 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_core_state_machine.c:510
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State INIT
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] mod_sofia.c:87
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 SOFIA INIT
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] sofia_glue.c:1197
>>>> sip:172.31.38.228:5060 Setting proxy route to
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] sofia_glue.c:1226
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 sending invite
>>>> version: 1.4.7 64bit 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> Local SDP: 152fb1fc-8673-11e4-9597-4be03abd148f v=0
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f o=FreeSWITCH 1418857238
>>>> 1418857239 IN IP4 172.31.32.243
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f s=FreeSWITCH
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f c=IN IP4 172.31.32.243
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f t=0 0
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f m=audio 21718 RTP/AVP 0
>>>> 8 101 13 152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:0
>>>> PCMU/8000 152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:8
>>>> PCMA/8000 152fb1fc-8673-11e4-9597-4be03abd148f a=rtpmap:101
>>>> telephone-event/8000 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> a=fmtp:101 0-16 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> a=ptime:20 152fb1fc-8673-11e4-9597-4be03abd148f a=sendrecv
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:40
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 Standard INIT
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:48
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State Change
>>>> CS_INIT -> CS_ROUTING 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 2014-12-18 05:02:36.267891 [DEBUG] switch_core_session.c:1387
>>>> Send signal sofia/sipinterface_1/20...@24.13.173.136:5062
>>>> [BREAK] 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:510
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State INIT
>>>> going to sleep 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) Running State
>>>> Change CS_ROUTING 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_core_state_machine.c:526
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State ROUTING
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] mod_sofia.c:123
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 SOFIA ROUTING
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_ivr_originate.c:67
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State Change
>>>> CS_ROUTING -> CS_CONSUME_MEDIA
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_session.c:1387 Send
>>>> signal sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:526
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State ROUTING
>>>> going to sleep 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_core_state_machine.c:470
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) Running State
>>>> Change CS_CONSUME_MEDIA 152fb1fc-8673-11e4-9597-4be03abd148f
>>>> 2014-12-18 05:02:36.267891 [DEBUG]
>>>> switch_core_state_machine.c:545
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State
>>>> CONSUME_MEDIA 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] switch_core_state_machine.c:545
>>>> (sofia/sipinterface_1/20...@24.13.173.136:5062) State
>>>> CONSUME_MEDIA going to sleep send 1181 bytes to
>>>> udp/[172.31.38.228]:5060 at 05:02:36.280913:
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> INVITE sip:20...@24.13.173.136:5062 SIP/2.0
>>>> Via: SIP/2.0/UDP
>>>> xx.172.103.138:11000;rport;branch=z9hG4bKmZ6N6H0mQSZ7N Route:
>>>> <sip:172.31.38.228:5060> Max-Forwards: 49 From: "2001"
>>>> <sip:...@test.com <javascript:>>;tag=2147tHjg7cemr To:
>>>> <sip:20...@24.13.173.136:5062> Call-ID:
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f CSeq: 69103414 INVITE
>>>> Contact: <sip:mod_...@xx.172.103.138:11000> User-Agent:
>>>> 2600hz Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE,
>>>> INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
>>>> Supported: 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: session Content-Length: 249 X-AUTH-IP:
>>>> 24.13.173.136 X-FS-Support: update_display,send_info
>>>> Remote-Party-ID: "2001" <sip:...@test.com
>>>> <javascript:>>;party=calling;screen=yes;privacy=off
>>>
>>>> v=0 o=FreeSWITCH 1418857238 1418857239 IN IP4 172.31.32.243
>>>> s=FreeSWITCH c=IN IP4 172.31.32.243 t=0 0 m=audio 21718
>>>> RTP/AVP 0 8 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000
>>>> a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20
>>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.267891
>>> [DEBUG]
>>>> switch_core_session.c:1052 Send signal
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.267891 [DEBUG] sofia.c:6413 Channel
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 entering state
>>>> <javascript:>>;tag=2147tHjg7cemr To:
>>>> <sip:20...@24.13.173.136:5062>;tag=1893664235 Call-ID:
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f CSeq: 69103414 INVITE
>>>> Contact: <sip:20...@24.13.173.136:5062> Allow: INVITE, INFO,
>>>> PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER,
>>>> SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE User-Agent:
>>>> Yealink SIP-T20P 9.72.0.30 Allow-Events:
>>>> talk,hold,conference,refer,check-sync Content-Length: 0
>>>
>>>>
>> ------------------------------------------------------------------------
>>
>>>
>>>>
>>>
>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18 05:02:36.647887
>>> [DEBUG]
>>>> switch_core_session.c:1052 Send signal
>>>> sofia/sipinterface_1/20...@24.13.173.136:5062 [BREAK]
>>>> 152fb1fc-8673-11e4-9597-4be03abd148f 2014-12-18
>>>> 05:02:36.647887 [DEBU...
>
>


- --
James Aimonetti
Lead Systems Architect / Impressionable Scallywag
"I thought I fixed that"

2600Hz | http://2600hz.com
sip:ja...@2600hz.com
tel:415.886.7905
irc:mc_ @ freenode
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQEcBAEBAgAGBQJUmx4BAAoJENTKa+JPXCVgX9UIAILWytJSles2f4E6ZCg5Lg3n
0egGqnr7bbRUtRcyC8lRHT0X3ht2Jrnvg9vYzmqbPsN7NvOEpPMs6P+S0oF4vHOz
yqKeIpBz80kqtUhm1hzQZDrHM2XQiJySz1Xns0Dm5NHzDLma2ZMF1ak+1n5+Cl03
2lokJzw8f7ty0uKkxJGBiLVP6A9B27SUYlZAwx/uYNkzgCHN18DramURJlrFvi9r
hqVCN+r4KQFMBLEdnVuVRe0NbXlG6hENboLwlGm9WDTJBVR1u9Vp8ZjFt/V4LIpU
0ZDCU0MxtRjdyi82qG+N6NyfL+rxnBMCKLGsI2IO1oNbv1xhyjKV4Ak321O6moY=
=auQ3
-----END PGP SIGNATURE-----

skor

unread,
Dec 25, 2014, 3:04:09 AM12/25/14
to 2600h...@googlegroups.com
> 2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8825 1 acls to check for proxy
> 2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8830 checking 172.31.38.228 against acl authoritative
> 2014-12-18 05:02:35.507926 [DEBUG] sofia.c:8870 IP 172.31.38.228 Rejected by acl "authoritative". Falling back to Digest auth.

sup -necallmgr ecallmgr_maintenance allow_sbc Kamailio 172.31.38.228

FS think that 172.31.38.228 is client-IP, not 24.13.173.136
Message has been deleted

rajesh,beaconnetx

unread,
Feb 23, 2015, 10:17:54 PM2/23/15
to 2600h...@googlegroups.com
Hi James, All,

We have fixed issue by adding fs_path with public IP address in the kamailio/default.cfg file. The Freeswitch does a proper NAT.
####### Kazoo Integration module ##########
loadmodule "db_kazoo.so"
modparam("db_kazoo", "node_hostname",  "xxxxxxxxxx")
modparam("db_kazoo", "register_fs_path", "aaa.bbb.ccc.ddd:5060")


We have noticed that the Freeswich does a routing of terminating call instead of routing the call to the Kamailio, but I guess this is by Design. We expected the Freeswitch to act as a B2BUA and Kamailio as Proxy.

Now when we installed kazoo-R15B-3.18-57.el6.x86_64 load, we were not able to add "register_fs_path". The kamailio does not start and we get following error - 
Feb 23 00:54:45 ip-172-31-37-166 kamailio: ERROR: <core> [modparam.c:152]: set_mod_param_regex(): set_mod_param_regex: parameter <register_fs_path> of type <1> not found in module <db_kazoo>

Any help will be appreciated.

Thanks,

Rajesh


Now when we installed in  
Reply all
Reply to author
Forward
0 new messages