search

plivo / plivoframework

Open Source Telephony Application Prototyping Framework
http://www.plivo.com/open-source/
Other
416 stars 180 forks source link

Redirect not working after conference #81

Open mattwilliamson opened 12 years ago

mattwilliamson commented 12 years ago

Given the following XML:

<Response>
    <Conference callbackUrl="http://localhost:81/_plivo/conference/callback" digitsMatch="123" endConferenceOnExit="true" hangupOnStar="True" maxMembers="5" muted="false" startConferenceOnEnter="true" stayAlone="false" timeLimit="0" waitSound="http://localhost:81/_plivo/redirect/callback/POST/aHR0cDovL2RsLmRyb3Bib3guY29tL3UvMTQ1NzMxNzkvVHdpbWwvU2ltcGxlL3dhaXRfbXVzaWMueG1s?Direction=inbound&amp;Channel-Read-Codec-Bit-Rate=64000&amp;Caller-Caller-ID-Number=8457026652&amp;CallerName=s&amp;variable_user_context=&amp;CallStatus=ringing&amp;variable_sip_Privacy=&amp;To=17602836505&amp;Caller-Privacy-Hide-Number=false&amp;variable_sip_P-Asserted-Identity=&amp;Channel-Privacy-Hide-Name=false&amp;From=8457026652&amp;Caller-Caller-ID-Name=s&amp;CallUUID=debbcd5a-0ffe-4235-9dac-21f7d62717b2">AC948550ad81934a1a9bcd33b689c0c236.1234</Conference>
    <Redirect>http://localhost:81/_plivo/redirect/POST/aHR0cDovL2RsLmRyb3Bib3guY29tL3UvMTQ1NzMxNzkvVE1ML3BsYXkueG1s</Redirect>
</Response>

I dial in with one phone and hear the wait music. I dial in with a second phone and they can talk to each other. I hang up on the second phone and I expect the Redirect to be executed. Instead, the first phone is hung up on the freeswitch side. If I add timeLimit to the Conference element, and only dial in with the first phone and wait for it to terminate from the timeout, it does execute the redirect.

mike-plivo commented 12 years ago

Ok, if you can paste the logs of first phone to see the call flow, thanks .

mattwilliamson commented 12 years ago

This is just one leg dialing in. Let me know if you want me to reproduce in full.

tport_wakeup_pri(0x2aaab4112e00): events IN
tport_recv_event(0x2aaab4112e00)
tport_recv_iovec(0x2aaab4112e00) msg 0x2aaab400dec0 from (udp/10.240.0.63:5060) has 1413 bytes, veclen = 1
tport_deliver(0x2aaab4112e00): msg 0x2aaab400dec0 (1413 bytes) from udp/75.101.162.138:5060/sip next=(nil)
nta: received INVITE sip:+1949266XXXX@myserver.com:5060 SIP/2.0 (CSeq 1)
nta: INVITE (1) going to a default leg
nta: timer set to 200 ms
nua: nua_stack_process_request: entering
nua: nh_create: entering
nua: nh_create_handle: entering
nua: nua_stack_set_params: entering
soa_clone(static::0x86263d0, 0x84a4550, 0x2aaab000db20) called
soa_set_params(static::0x2aaab0021640, ...) called
nta_leg_tcreate(0x2aaab0027f30)
soa_init_offer_answer(static::0x2aaab0021640) called
soa_set_remote_sdp(static::0x2aaab0021640, (nil), 0x2aaab4005985, 224) called
nua(0x2aaab000db20): adding session usage
tport_tsend(0x2aaab4112e00) tpn = UDP/75.101.162.138:5060
tport_resolve addrinfo = 75.101.162.138:5060
tport_by_addrinfo(0x2aaab4112e00): not found by name UDP/75.101.162.138:5060
tport_vsend(0x2aaab4112e00): 867 bytes of 867 to udp/75.101.162.138:5060
tport_vsend returned 867
nta: sent 100 Trying for INVITE (1)
nua(0x2aaab000db20): event i_invite 100 Trying
nua(0x2aaab000db20): call state changed: init -> received, received offer
soa_get_remote_sdp(static::0x2aaab0021640, [0x418158b8], [0x418158b0], [(nil)]) called
nua(0x2aaab000db20): event i_state 100 Trying
nua: nua_application_event: entering
nua: nua_handle_bind: entering
nua: nua_application_event: entering
nua: nua_handle_magic: entering
nua: nua_handle_magic: entering
2012-03-21 08:36:17.726445 [DEBUG] sofia.c:7516 IP 75.101.162.138 Approved by acl "domains[]". Access Granted.
2012-03-21 08:36:17.726445 [NOTICE] switch_channel.c:926 New Channel sofia/internal/+1732276XXXX@flowroute.com [5f3a73ce-a306-4343-a0f0-0d26a2e847db]
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_NEW
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:380 (sofia/internal/+1732276XXXX@flowroute.com) State NEW
nua: nua_handle_magic: entering
2012-03-21 08:36:17.726445 [DEBUG] sofia.c:5532 Channel sofia/internal/+1732276XXXX@flowroute.com entering state [received][100]
2012-03-21 08:36:17.726445 [DEBUG] sofia.c:5543 Remote SDP:
v=0
o=- 326070273 1332331387 IN IP4 66.42.121.4
s=-
c=IN IP4 66.42.121.4
t=0 0
m=audio 29124 RTP/AVP 0 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2012-03-21 08:36:17.726445 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000]
2012-03-21 08:36:17.726445 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000]
2012-03-21 08:36:17.726445 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
2012-03-21 08:36:17.726445 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-03-21 08:36:17.726445 [DEBUG] sofia_glue.c:2996 Set Codec sofia/internal/+1732276XXXX@flowroute.com PCMU/8000 20 ms 160 samples 64000 bits
2012-03-21 08:36:17.726445 [DEBUG] switch_core_codec.c:111 sofia/internal/+1732276XXXX@flowroute.com Original read codec set to PCMU:0
2012-03-21 08:36:17.726445 [DEBUG] sofia_glue.c:5000 Set 2833 dtmf send/recv payload to 101
2012-03-21 08:36:17.726445 [DEBUG] sofia.c:5757 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_NEW -> CS_INIT
2012-03-21 08:36:17.726445 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
nua: nua_handle_magic: entering
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_INIT
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/+1732276XXXX@flowroute.com) State INIT
2012-03-21 08:36:17.726445 [DEBUG] mod_sofia.c:85 sofia/internal/+1732276XXXX@flowroute.com SOFIA INIT
2012-03-21 08:36:17.726445 [DEBUG] mod_sofia.c:125 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_INIT -> CS_ROUTING
2012-03-21 08:36:17.726445 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/+1732276XXXX@flowroute.com) State INIT going to sleep
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_ROUTING
2012-03-21 08:36:17.726445 [DEBUG] switch_channel.c:1886 (sofia/internal/+1732276XXXX@flowroute.com) Callstate Change DOWN -> RINGING
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/+1732276XXXX@flowroute.com) State ROUTING
2012-03-21 08:36:17.726445 [DEBUG] mod_sofia.c:148 sofia/internal/+1732276XXXX@flowroute.com SOFIA ROUTING
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:104 sofia/internal/+1732276XXXX@flowroute.com Standard ROUTING
2012-03-21 08:36:17.726445 [INFO] mod_dialplan_xml.c:485 Processing LAKEWOOD, NJ <+1732276XXXX>->+1949266XXXX in context public
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->unloop] continue=false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->outside_call] continue=true
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Absolute Condition [outside_call]
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action set(outside_call=true) 
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->call_debug] continue=true
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (PASS) [call_debug] ${call_debug}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action info() 
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->plivo_public_did] continue=false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (PASS) [plivo_public_did] destination_number(+1949266XXXX) =~ /^\+?(\d+)$/ break=on-false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action enable_heartbeat(60) 
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action socket(127.0.0.1:8084 async full) 
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_ROUTING -> CS_EXECUTE
2012-03-21 08:36:17.726445 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/+1732276XXXX@flowroute.com) State ROUTING going to sleep
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_EXECUTE
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/+1732276XXXX@flowroute.com) State EXECUTE
2012-03-21 08:36:17.726445 [DEBUG] mod_sofia.c:241 sofia/internal/+1732276XXXX@flowroute.com SOFIA EXECUTE
2012-03-21 08:36:17.726445 [DEBUG] switch_core_state_machine.c:192 sofia/internal/+1732276XXXX@flowroute.com Standard EXECUTE
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(outside_call=true)
2012-03-21 08:36:17.726445 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [outside_call]=[true]
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(RFC2822_DATE=Wed, 21 Mar 2012 08:36:17 -0400)
2012-03-21 08:36:17.726445 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [RFC2822_DATE]=[Wed, 21 Mar 2012 08:36:17 -0400]
EXECUTE sofia/internal/+1732276XXXX@flowroute.com info()
2012-03-21 08:36:17.726445 [INFO] mod_dptools.c:1439 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-Call-State: [RINGING]
Channel-State-Number: [4]
Channel-Name: [sofia/internal/+1732276XXXX@flowroute.com]
Unique-ID: [5f3a73ce-a306-4343-a0f0-0d26a2e847db]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Presence-ID: [+1732276XXXX@flowroute.com]
Channel-Call-UUID: [5f3a73ce-a306-4343-a0f0-0d26a2e847db]
Answer-State: [ringing]
Channel-Read-Codec-Name: [PCMU]
Channel-Read-Codec-Rate: [8000]
Channel-Read-Codec-Bit-Rate: [64000]
Channel-Write-Codec-Name: [PCMU]
Channel-Write-Codec-Rate: [8000]
Channel-Write-Codec-Bit-Rate: [64000]
Caller-Direction: [inbound]
Caller-Username: [+1732276XXXX]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [LAKEWOOD, NJ]
Caller-Caller-ID-Number: [+1732276XXXX]
Caller-Network-Addr: [75.101.162.138]
Caller-ANI: [+1732276XXXX]
Caller-Destination-Number: [+1949266XXXX]
Caller-Unique-ID: [5f3a73ce-a306-4343-a0f0-0d26a2e847db]
Caller-Source: [mod_sofia]
Caller-Context: [public]
Caller-Channel-Name: [sofia/internal/+1732276XXXX@flowroute.com]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1332333377726445]
Caller-Channel-Created-Time: [1332333377726445]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [5f3a73ce-a306-4343-a0f0-0d26a2e847db]
variable_session_id: [102]
variable_sip_local_network_addr: [10.240.0.63]
variable_sip_network_ip: [75.101.162.138]
variable_sip_network_port: [5060]
variable_sip_received_ip: [75.101.162.138]
variable_sip_received_port: [5060]
variable_sip_via_protocol: [udp]
variable_sip_authorized: [true]
variable_sip_acl_authed_by: [domains]
variable_sip_from_user: [+1732276XXXX]
variable_sip_from_uri: [+1732276XXXX@flowroute.com]
variable_sip_from_host: [flowroute.com]
variable_sip_from_user_stripped: [1732276XXXX]
variable_sip_from_tag: [3541322082-790605]
variable_sofia_profile_name: [internal]
variable_sip_P-Asserted-Identity: [+1732276XXXX]
variable_sip_cid_type: [pid]
variable_sip_invite_record_route: [<sip:75.101.162.138;ftag=3541322082-790605;lr>,<sip:216.115.69.144;lr>,<sip:216.115.69.132;lr>]
variable_sip_full_via: [SIP/2.0/UDP 75.101.162.138;branch=z9hG4bKe36d.cabcea67.0,SIP/2.0/UDP 216.115.69.144;branch=z9hG4bKe36d.0588baa4879bd2710a5069eec3b6e1a5.0,SIP/2.0/UDP 216.115.69.131;branch=z9hG4bKe36d.1aa97631f97056d9aa268159665a4b6f.0,SIP/2.0/UDP 216.115.69.132;branch=z9hG4bKe36d.d2aef258917df02049f6def4e510eee9.0,SIP/2.0/UDP 66.42.120.184:5060;branch=z9hG4bK782bd4aa8813192fdb942fc543b4a19c]
variable_sip_from_display: [LAKEWOOD, NJ]
variable_sip_full_from: ["LAKEWOOD, NJ" <sip:+1732276XXXX@flowroute.com>;tag=3541322082-790605]
variable_sip_full_to: [<sip:+1949266XXXX@flowroute.com>]
variable_sip_req_user: [+1949266XXXX]
variable_sip_req_port: [5060]
variable_sip_req_uri: [+1949266XXXX@myserver.com:5060]
variable_sip_req_host: [myserver.com]
variable_sip_to_user: [+1949266XXXX]
variable_sip_to_uri: [+1949266XXXX@flowroute.com]
variable_sip_to_host: [flowroute.com]
variable_sip_contact_user: [+1732276XXXX]
variable_sip_contact_port: [5060]
variable_sip_contact_uri: [+1732276XXXX@66.42.120.184:5060]
variable_sip_contact_host: [66.42.120.184]
variable_channel_name: [sofia/internal/+1732276XXXX@flowroute.com]
variable_sip_call_id: [73933709-3541322082-790598@gsbc06-lsan.mdsg-pacwest.com]
variable_sip_via_host: [75.101.162.138]
variable_max_forwards: [65]
variable_presence_id: [+1732276XXXX@flowroute.com]
variable_sip_h_X-Payphone: [false]
variable_sip_h_P-App-Name: [spoofcard]
variable_sip_h_P-App-Param: [setid=44;productid=1;product_id=1;app=spoofcard;default_cc=1;language=en]
variable_switch_r_sdp: [v=0
o=- 326070273 1332331387 IN IP4 66.42.121.4
s=-
c=IN IP4 66.42.121.4
t=0 0
m=audio 29124 RTP/AVP 0 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
]
variable_remote_media_ip: [66.42.121.4]
variable_remote_media_port: [29124]
variable_sip_audio_recv_pt: [0]
variable_sip_use_codec_name: [PCMU]
variable_sip_use_codec_rate: [8000]
variable_sip_use_codec_ptime: [20]
variable_read_codec: [PCMU]
variable_read_rate: [8000]
variable_write_codec: [PCMU]
variable_write_rate: [8000]
variable_endpoint_disposition: [RECEIVED]
variable_DP_MATCH: [ARRAY::+1949266XXXX|:1949266XXXX]
variable_call_uuid: [5f3a73ce-a306-4343-a0f0-0d26a2e847db]
variable_outside_call: [true]
variable_RFC2822_DATE: [Wed, 21 Mar 2012 08:36:17 -0400]
variable_current_application: [info]

EXECUTE sofia/internal/+1732276XXXX@flowroute.com enable_heartbeat(60)
2012-03-21 08:36:17.726445 [INFO] switch_core_session.c:1334 sofia/internal/+1732276XXXX@flowroute.com setting session heartbeat to 60 second(s).
EXECUTE sofia/internal/+1732276XXXX@flowroute.com socket(127.0.0.1:8084 async full)
2012-03-21 08:36:17.746444 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:17.746444 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:17.766456 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(plivo_app=true)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(plivo_app=true)
2012-03-21 08:36:17.766456 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [plivo_app]=[true]
2012-03-21 08:36:17.766456 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(hangup_after_bridge=false)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(hangup_after_bridge=false)
2012-03-21 08:36:17.766456 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [hangup_after_bridge]=[false]
nta: timer not set
2012-03-21 08:36:18.106424 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.106424 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.106424 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.106424 [DEBUG] mod_event_socket.c:2633 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_EXECUTE -> CS_RESET
2012-03-21 08:36:18.106424 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.126432 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute pre_answer()
EXECUTE sofia/internal/+1732276XXXX@flowroute.com pre_answer()
2012-03-21 08:36:18.126432 [INFO] mod_dptools.c:1161 Sending early media
2012-03-21 08:36:18.126432 [DEBUG] sofia_glue.c:3248 AUDIO RTP [sofia/internal/+1732276XXXX@flowroute.com] 10.240.0.63 port 16470 -> 66.42.121.4 port 29124 codec: 0 ms: 20
2012-03-21 08:36:18.126432 [DEBUG] switch_rtp.c:1661 Starting timer [soft] 160 bytes per 20ms
2012-03-21 08:36:18.126432 [DEBUG] sofia_glue.c:3512 Set 2833 dtmf send payload to 101
2012-03-21 08:36:18.126432 [DEBUG] sofia_glue.c:3518 Set 2833 dtmf receive payload to 101
2012-03-21 08:36:18.126432 [DEBUG] mod_sofia.c:2576 Ring SDP:
v=0
o=FreeSWITCH 1332316908 1332316909 IN IP4 10.240.0.63
s=FreeSWITCH
c=IN IP4 10.240.0.63
t=0 0
m=audio 16470 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2012-03-21 08:36:18.126432 [NOTICE] mod_sofia.c:2579 Pre-Answer sofia/internal/+1732276XXXX@flowroute.com!
2012-03-21 08:36:18.126432 [DEBUG] switch_channel.c:2932 (sofia/internal/+1732276XXXX@flowroute.com) Callstate Change RINGING -> EARLY
nua: nua_respond: entering
nua(0x2aaab000db20): sent signal r_respond
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:731 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
nua(0x2aaab000db20): recv signal r_respond 183 Session Progress
nua: nua_stack_set_params: entering
soa_set_params(static::0x2aaab0021640, ...) called
soa_set_user_sdp(static::0x2aaab0021640, (nil), 0x8465c04, -1) called
soa_set_capability_sdp(static::0x2aaab0021640, (nil), 0x8465c04, -1) called
2012-03-21 08:36:18.126432 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(plivo_sip_transfer_uri=sip:+1949266XXXX@72.9.136.119)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(plivo_sip_transfer_uri=sip:+1949266XXXX@72.9.136.119)
nua: nua_invite_server_respond: entering
soa_generate_answer(static::0x2aaab0021640) called
soa_static_offer_answer_action(0x2aaab0021640, soa_generate_answer): called
soa_static(0x2aaab0021640, soa_generate_answer): generating local description
soa_static(0x2aaab0021640, soa_generate_answer): upgrade with remote description
soa_sdp_mode_set(0x41815cd0, 0x2aaab005ef90, ""): called
soa_static(0x2aaab0021640, soa_generate_answer): storing local description
soa_activate(static::0x2aaab0021640, (nil)) called
soa_get_local_sdp(static::0x2aaab0021640, [(nil)], [0x41815e38], [0x41815e44]) called
tport_tsend(0x2aaab4112e00) tpn = UDP/75.101.162.138:5060
tport_resolve addrinfo = 75.101.162.138:5060
tport_by_addrinfo(0x2aaab4112e00): not found by name UDP/75.101.162.138:5060
2012-03-21 08:36:18.126432 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [plivo_sip_transfer_uri]=[sip:+1949266XXXX@72.9.136.119]
tport_vsend(0x2aaab4112e00): 1657 bytes of 1657 to udp/75.101.162.138:5060
tport_vsend returned 1657
nta: sent 183 Session Progress for INVITE (1)
nta: timer set to 60000 ms
nua(0x2aaab000db20): call state changed: received -> early, sent answer
soa_get_local_sdp(static::0x2aaab0021640, [0x41815ef8], [0x41815ef0], [(nil)]) called
soa_get_params(static::0x2aaab0021640, ...) called
nua(0x2aaab000db20): event i_state 183 Session Progress
nua: nua_application_event: entering
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:877 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
nua: nua_handle_magic: entering
2012-03-21 08:36:18.126432 [DEBUG] sofia.c:5525 Channel sofia/internal/+1732276XXXX@flowroute.com skipping state [early][183]
nua: nua_handle_magic: entering
2012-03-21 08:36:18.126432 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute redirect(sip:+1949266XXXX@72.9.136.119)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com redirect(sip:+1949266XXXX@72.9.136.119)
2012-03-21 08:36:18.126432 [DEBUG] mod_sofia.c:2282 Redirecting to "unknown" <sip:+1949266XXXX@72.9.136.119>
nua: nua_respond: entering
nua(0x2aaab000db20): sent signal r_respond
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:731 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
nua(0x2aaab000db20): recv signal r_respond 302 Moved Temporarily
nua: nua_stack_set_params: entering
soa_set_params(static::0x2aaab0021640, ...) called
nua: nua_invite_server_respond: entering
soa_clear_remote_sdp(static::0x2aaab0021640) called
tport_tsend(0x2aaab4112e00) tpn = UDP/75.101.162.138:5060
tport_resolve addrinfo = 75.101.162.138:5060
tport_by_addrinfo(0x2aaab4112e00): not found by name UDP/75.101.162.138:5060
tport_vsend(0x2aaab4112e00): 1236 bytes of 1236 to udp/75.101.162.138:5060
tport_vsend returned 1236
nta: sent 302 Moved Temporarily for INVITE (1)
nta: timer shortened to 500 ms
nua(0x2aaab000db20): removing session usage
nua(0x2aaab000db20): call state changed: early -> terminated
nua(0x2aaab000db20): event i_state 302 Moved Temporarily
nua(0x2aaab000db20): event i_terminated 302 Moved Temporarily
soa_destroy(static::0x2aaab0021640) called
nta_leg_destroy(0x2aaab0027f30)
2012-03-21 08:36:18.126432 [DEBUG] mod_event_socket.c:506 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_RESET -> CS_EXECUTE
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.126432 [NOTICE] switch_core_state_machine.c:226 sofia/internal/+1732276XXXX@flowroute.com has executed the last dialplan instruction, hanging up.
2012-03-21 08:36:18.126432 [DEBUG] switch_channel.c:2848 (sofia/internal/+1732276XXXX@flowroute.com) Callstate Change EARLY -> HANGUP
2012-03-21 08:36:18.126432 [NOTICE] switch_core_state_machine.c:228 Hangup sofia/internal/+1732276XXXX@flowroute.com [CS_EXECUTE] [NORMAL_CLEARING]
2012-03-21 08:36:18.126432 [DEBUG] switch_channel.c:2871 Send signal sofia/internal/+1732276XXXX@flowroute.com [KILL]
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/+1732276XXXX@flowroute.com) State EXECUTE going to sleep
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_HANGUP
nua: nua_application_event: entering
nua: nua_application_event: entering
nua: nua_handle_magic: entering
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/+1732276XXXX@flowroute.com) State HANGUP
2012-03-21 08:36:18.126432 [DEBUG] mod_sofia.c:469 Channel sofia/internal/+1732276XXXX@flowroute.com hanging up, cause: NORMAL_CLEARING
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:47 sofia/internal/+1732276XXXX@flowroute.com Standard HANGUP, cause: NORMAL_CLEARING
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/+1732276XXXX@flowroute.com) State HANGUP going to sleep
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:393 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_HANGUP -> CS_REPORTING
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_REPORTING
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/+1732276XXXX@flowroute.com) State REPORTING
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:79 sofia/internal/+1732276XXXX@flowroute.com Standard REPORTING, cause: NORMAL_CLEARING
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/+1732276XXXX@flowroute.com) State REPORTING going to sleep
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:387 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_REPORTING -> CS_DESTROY
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:36:18.126432 [DEBUG] switch_core_session.c:1382 Session 102 (sofia/internal/+1732276XXXX@flowroute.com) Locked, Waiting on external entities
2012-03-21 08:36:18.126432 [NOTICE] switch_core_session.c:1400 Session 102 (sofia/internal/+1732276XXXX@flowroute.com) Ended
2012-03-21 08:36:18.126432 [NOTICE] switch_core_session.c:1402 Close Channel sofia/internal/+1732276XXXX@flowroute.com [CS_DESTROY]
nua: nua_handle_magic: entering
nua: nua_handle_magic: entering
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/+1732276XXXX@flowroute.com) Callstate Change HANGUP -> DOWN
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:494 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_DESTROY
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/+1732276XXXX@flowroute.com) State DESTROY
2012-03-21 08:36:18.126432 [DEBUG] mod_sofia.c:374 sofia/internal/+1732276XXXX@flowroute.com SOFIA DESTROY
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:86 sofia/internal/+1732276XXXX@flowroute.com Standard DESTROY
2012-03-21 08:36:18.126432 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/+1732276XXXX@flowroute.com) State DESTROY going to sleep
tport_wakeup_pri(0x2aaab4112e00): events IN
tport_recv_event(0x2aaab4112e00)
tport_recv_iovec(0x2aaab4112e00) msg 0x2aaab4005a70 from (udp/10.240.0.63:5060) has 430 bytes, veclen = 1
tport_deliver(0x2aaab4112e00): msg 0x2aaab4005a70 (430 bytes) from udp/75.101.162.138:5060/sip next=(nil)
nta: received ACK sip:+1949266XXXX@myserver.com:5060 SIP/2.0 (CSeq 1)
nta: ACK (1) is going to INVITE (1)
nta: timer set next to 4510 ms
nta: timer I fired, terminate 302 response
incoming_reclaim_all((nil), (nil), 0x41815d40)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
freeswitch@internal>
mike-plivo commented 12 years ago

What that SIP redirect(sip:+1949266XXXX@72.9.136.119) ?

mattwilliamson commented 12 years ago

Oops, yah, forgot about the redirect. Here's the destination server log:

2012-03-21 08:51:38.097308 [DEBUG] sofia.c:7516 IP 75.101.162.138 Approved by acl "domains[]". Access Granted.
2012-03-21 08:51:38.097308 [NOTICE] switch_channel.c:926 New Channel sofia/internal/+1732276XXXX@flowroute.com [fd495b27-b2c2-4054-94c5-af789d66ad7d]
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_NEW
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:380 (sofia/internal/+1732276XXXX@flowroute.com) State NEW
2012-03-21 08:51:38.097308 [DEBUG] sofia.c:5532 Channel sofia/internal/+1732276XXXX@flowroute.com entering state [received][100]
2012-03-21 08:51:38.097308 [DEBUG] sofia.c:5543 Remote SDP:
v=0
o=- 323003393 1332332631 IN IP4 66.42.121.4
s=-
c=IN IP4 66.42.121.4
t=0 0
m=audio 31370 RTP/AVP 0 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2012-03-21 08:51:38.097308 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000]
2012-03-21 08:51:38.097308 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000]
2012-03-21 08:51:38.097308 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
2012-03-21 08:51:38.097308 [DEBUG] sofia_glue.c:4879 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-03-21 08:51:38.097308 [DEBUG] sofia_glue.c:2996 Set Codec sofia/internal/+1732276XXXX@flowroute.com PCMU/8000 20 ms 160 samples 64000 bits
2012-03-21 08:51:38.097308 [DEBUG] switch_core_codec.c:111 sofia/internal/+1732276XXXX@flowroute.com Original read codec set to PCMU:0
2012-03-21 08:51:38.097308 [DEBUG] sofia_glue.c:5000 Set 2833 dtmf send/recv payload to 101
2012-03-21 08:51:38.097308 [DEBUG] sofia.c:5757 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_NEW -> CS_INIT
2012-03-21 08:51:38.097308 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_INIT
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/+1732276XXXX@flowroute.com) State INIT
2012-03-21 08:51:38.097308 [DEBUG] mod_sofia.c:85 sofia/internal/+1732276XXXX@flowroute.com SOFIA INIT
2012-03-21 08:51:38.097308 [DEBUG] mod_sofia.c:125 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_INIT -> CS_ROUTING
2012-03-21 08:51:38.097308 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:401 (sofia/internal/+1732276XXXX@flowroute.com) State INIT going to sleep
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_ROUTING
2012-03-21 08:51:38.097308 [DEBUG] switch_channel.c:1886 (sofia/internal/+1732276XXXX@flowroute.com) Callstate Change DOWN -> RINGING
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/+1732276XXXX@flowroute.com) State ROUTING
2012-03-21 08:51:38.097308 [DEBUG] mod_sofia.c:148 sofia/internal/+1732276XXXX@flowroute.com SOFIA ROUTING
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:104 sofia/internal/+1732276XXXX@flowroute.com Standard ROUTING
2012-03-21 08:51:38.097308 [INFO] mod_dialplan_xml.c:485 Processing LAKEWOOD, NJ <+1732276XXXX>->+19492660933 in context public
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->unloop] continue=false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->outside_call] continue=true
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Absolute Condition [outside_call]
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action set(outside_call=true) 
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->call_debug] continue=true
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/+1732276XXXX@flowroute.com parsing [public->plivo_public_did] continue=false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Regex (PASS) [plivo_public_did] destination_number(+19492660933) =~ /^\+?(\d+)$/ break=on-false
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action enable_heartbeat(60) 
Dialplan: sofia/internal/+1732276XXXX@flowroute.com Action socket(127.0.0.1:8084 async full) 
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:154 (sofia/internal/+1732276XXXX@flowroute.com) State Change CS_ROUTING -> CS_EXECUTE
2012-03-21 08:51:38.097308 [DEBUG] switch_core_session.c:1182 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:410 (sofia/internal/+1732276XXXX@flowroute.com) State ROUTING going to sleep
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:362 (sofia/internal/+1732276XXXX@flowroute.com) Running State Change CS_EXECUTE
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:417 (sofia/internal/+1732276XXXX@flowroute.com) State EXECUTE
2012-03-21 08:51:38.097308 [DEBUG] mod_sofia.c:241 sofia/internal/+1732276XXXX@flowroute.com SOFIA EXECUTE
2012-03-21 08:51:38.097308 [DEBUG] switch_core_state_machine.c:192 sofia/internal/+1732276XXXX@flowroute.com Standard EXECUTE
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(outside_call=true)
2012-03-21 08:51:38.097308 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [outside_call]=[true]
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(RFC2822_DATE=Wed, 21 Mar 2012 08:51:38 -0400)
2012-03-21 08:51:38.097308 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [RFC2822_DATE]=[Wed, 21 Mar 2012 08:51:38 -0400]
EXECUTE sofia/internal/+1732276XXXX@flowroute.com enable_heartbeat(60)
2012-03-21 08:51:38.097308 [INFO] switch_core_session.c:1334 sofia/internal/+1732276XXXX@flowroute.com setting session heartbeat to 60 second(s).
EXECUTE sofia/internal/+1732276XXXX@flowroute.com socket(127.0.0.1:8084 async full)
2012-03-21 08:51:38.117303 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.117303 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.117303 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(plivo_app=true)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(plivo_app=true)
2012-03-21 08:51:38.117303 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [plivo_app]=[true]
2012-03-21 08:51:38.117303 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(hangup_after_bridge=false)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(hangup_after_bridge=false)
2012-03-21 08:51:38.117303 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [hangup_after_bridge]=[false]
2012-03-21 08:51:38.657289 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.657289 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.657289 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.657289 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute answer()
EXECUTE sofia/internal/+1732276XXXX@flowroute.com answer()
2012-03-21 08:51:38.657289 [DEBUG] sofia_glue.c:3248 AUDIO RTP [sofia/internal/+1732276XXXX@flowroute.com] 10.240.0.62 port 20774 -> 66.42.121.4 port 31370 codec: 0 ms: 20
2012-03-21 08:51:38.657289 [DEBUG] switch_rtp.c:1661 Starting timer [soft] 160 bytes per 20ms
2012-03-21 08:51:38.657289 [DEBUG] sofia_glue.c:3512 Set 2833 dtmf send payload to 101
2012-03-21 08:51:38.657289 [DEBUG] sofia_glue.c:3518 Set 2833 dtmf receive payload to 101
2012-03-21 08:51:38.657289 [DEBUG] mod_sofia.c:750 Local SDP sofia/internal/+1732276XXXX@flowroute.com:
v=0
o=FreeSWITCH 1332313524 1332313525 IN IP4 10.240.0.62
s=FreeSWITCH
c=IN IP4 10.240.0.62
t=0 0
m=audio 20774 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2012-03-21 08:51:38.657289 [DEBUG] switch_core_session.c:731 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.657289 [DEBUG] switch_channel.c:3190 (sofia/internal/+1732276XXXX@flowroute.com) Callstate Change RINGING -> ACTIVE
2012-03-21 08:51:38.657289 [NOTICE] mod_dptools.c:1135 Channel [sofia/internal/+1732276XXXX@flowroute.com] has been answered
2012-03-21 08:51:38.657289 [DEBUG] switch_core_session.c:877 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:38.657289 [DEBUG] sofia.c:5532 Channel sofia/internal/+1732276XXXX@flowroute.com entering state [completed][200]
2012-03-21 08:51:38.657289 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(conference_controls=none)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(conference_controls=none)
2012-03-21 08:51:38.657289 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [conference_controls]=[none]
2012-03-21 08:51:38.657289 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(conference_max_members=5)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(conference_max_members=5)
2012-03-21 08:51:38.657289 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [conference_max_members]=[5]
2012-03-21 08:51:39.077279 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:39.077279 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:39.077279 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:39.077279 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:39.097280 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(playback_delimiter=!)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(playback_delimiter=!)
2012-03-21 08:51:39.097280 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [playback_delimiter]=[!]
2012-03-21 08:51:39.097280 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(conference_moh_sound=file_string://silence_stream://1!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Claude%20Debussy%20-%20Claire%20de%20Lune%20-%20Piano.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Mozart%20-%20Piano%20Sonata%20-%20Rondo%20alla%20turca.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Classical%20-%20Bethoven%20-%20Moonlight%20Sonata.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Chopin%20-%20Etude%20Op.%2010%2C%20No.%2012%20in%20C%20Minor%20%28Revolutionary%20Etude%29.mp3)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(conference_moh_sound=file_string://silence_stream://1!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Claude%20Debussy%20-%20Claire%20de%20Lune%20-%20Piano.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Mozart%20-%20Piano%20Sonata%20-%20Rondo%20alla%20turca.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Classical%20-%20Bethoven%20-%20Moonlight%20Sonata.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Chopin%20-%20Etude%20Op.%2010%2C%20No.%2012%20in%20C%20Minor%20%28Revolutionary%20Etude%29.mp3)
2012-03-21 08:51:39.097280 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [conference_moh_sound]=[file_string://silence_stream://1!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Claude%20Debussy%20-%20Claire%20de%20Lune%20-%20Piano.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Mozart%20-%20Piano%20Sonata%20-%20Rondo%20alla%20turca.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Classical%20-%20Bethoven%20-%20Moonlight%20Sonata.mp3!shout://dl.dropbox.com/u/14573179/Audio/Hold%20Music/Chopin%20-%20Etude%20Op.%2010%2C%20No.%2012%20in%20C%20Minor%20%28Revolutionary%20Etude%29.mp3]
2012-03-21 08:51:39.097280 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute set(conference_member_flags=moderator,mintwo,endconf)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com set(conference_member_flags=moderator,mintwo,endconf)
2012-03-21 08:51:39.097280 [DEBUG] mod_dptools.c:1281 sofia/internal/+1732276XXXX@flowroute.com SET [conference_member_flags]=[moderator,mintwo,endconf]
2012-03-21 08:51:39.097280 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute conference(AC948550ad81934a1a9bcd33b689c0c236.1234@plivo)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com conference(AC948550ad81934a1a9bcd33b689c0c236.1234@plivo)
2012-03-21 08:51:39.097280 [INFO] mod_conference.c:7268 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie
2012-03-21 08:51:39.097280 [DEBUG] mod_conference.c:6097 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2012-03-21 08:51:39.097280 [DEBUG] mod_conference.c:6142 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2012-03-21 08:51:39.097280 [DEBUG] switch_core_codec.c:216 sofia/internal/+1732276XXXX@flowroute.com Push codec L16:70
2012-03-21 08:51:39.097280 [DEBUG] switch_core_session.c:731 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:39.097280 [DEBUG] mod_conference.c:2863 Setup timer soft success interval: 20  samples: 160
2012-03-21 08:51:39.097280 [DEBUG] mod_conference.c:1340 Setup timer success interval: 20  samples: 160
2012-03-21 08:51:39.097280 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:39.097280 [DEBUG] switch_core_session.c:1014 Send signal sofia/internal/+1732276XXXX@flowroute.com [BREAK]
2012-03-21 08:51:39.117280 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute bind_digit_action(plivo_bda_fd495b27-b2c2-4054-94c5-af789d66ad7d,123,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=fd495b27-b2c2-4054-94c5-af789d66ad7d,Callback-Url=http://localhost:81/_plivo/conference/callback,Callback-Method=POST,Member-ID=5,Conference-Name=AC948550ad81934a1a9bcd33b689c0c236.1234,Conference-Unique-ID=2b74589c-ba42-4d67-b17f-a09c0a357582,Digits-Match=123')
EXECUTE sofia/internal/+1732276XXXX@flowroute.com bind_digit_action(plivo_bda_fd495b27-b2c2-4054-94c5-af789d66ad7d,123,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=fd495b27-b2c2-4054-94c5-af789d66ad7d,Callback-Url=http://localhost:81/_plivo/conference/callback,Callback-Method=POST,Member-ID=5,Conference-Name=AC948550ad81934a1a9bcd33b689c0c236.1234,Conference-Unique-ID=2b74589c-ba42-4d67-b17f-a09c0a357582,Digits-Match=123')
2012-03-21 08:51:39.117280 [INFO] switch_ivr_async.c:194 Digit parser DPTOOLS: Setting realm to 'plivo_bda_fd495b27-b2c2-4054-94c5-af789d66ad7d'
2012-03-21 08:51:39.117280 [DEBUG] switch_ivr_async.c:288 Digit parser DPTOOLS: binding 123/plivo_bda_fd495b27-b2c2-4054-94c5-af789d66ad7d/0 callback: 0x2aaab8853f10 data: 0x2aaaac04ddc0
2012-03-21 08:51:39.117280 [DEBUG] switch_ivr.c:591 sofia/internal/+1732276XXXX@flowroute.com Command Execute digit_action_set_realm(plivo_bda_fd495b27-b2c2-4054-94c5-af789d66ad7d)
EXECUTE sofia/internal/+1732276XXXX@flowroute.com digit_action_set_realm(plivo_bda_fd495b27-b2c2-4054-94c5-af789d66ad7d)
2012-03-21 08:51:39.117280 [INFO] switch_ivr_async.c:194 Digit parser DPTOOLS: Setting realm to 'plivo_bda_fd495b27-b2c2-4054-94c5-af789d66ad7d'
2012-03-21 08:51:39.197275 [DEBUG] switch_rtp.c:3210 Correct ip/port confirmed.
freeswitch@internal>