Hello, I have encountered strange problem - there is no audible ringback on DID routing. Dialplan is simple, on DID call gets transferred to local extension. Local extension is pretty much vanilla. Log shows that both 183/180 is being fired and ringback activated but no sound coming. Ringing is going ok though, as well as connection afterwords. Is that incoming provider's problem or freeswitch? Regards, Paul Kazakov Log: Dialplan: sofia/external/mobile@provider Action transfer(20 XML default) 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:216 (sofia/external/mobile@provider) State Change CS_ROUTING -> CS_EXECUTE 2015-10-26 01:39:27.463856 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/mobile@provider [BREAK] 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:528 (sofia/external/mobile@provider) State ROUTING going to sleep 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:472 (sofia/external/mobile@provider) Running State Change CS_EXECUTE 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:535 (sofia/external/mobile@provider) State EXECUTE 2015-10-26 01:39:27.463856 [DEBUG] mod_sofia.c:178 sofia/external/mobile@provider SOFIA EXECUTE 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:258 sofia/external/mobile@provider Standard EXECUTE EXECUTE sofia/external/mobile@provider set(outside_call=true) 2015-10-26 01:39:27.463856 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [outside_call]=[true] EXECUTE sofia/external/mobile@provider export(RFC2822_DATE=Mon, 26 Oct 2015 01:39:27 +0100) 2015-10-26 01:39:27.483860 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 26 Oct 2015 01:39:27 +0100] EXECUTE sofia/external/mobile@provider set(domain_name=192.168.1.5) 2015-10-26 01:39:27.483860 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [domain_name]=[192.168.1.5] EXECUTE sofia/external/mobile@provider transfer(20 XML default) 2015-10-26 01:39:27.483860 [DEBUG] switch_ivr.c:1856 (sofia/external/mobile@provider) State Change CS_EXECUTE -> CS_ROUTING 2015-10-26 01:39:27.483860 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/mobile@provider [BREAK] 2015-10-26 01:39:27.483860 [DEBUG] switch_core_session.c:913 Send signal sofia/external/mobile@provider [BREAK] 2015-10-26 01:39:27.483860 [NOTICE] switch_ivr.c:1863 Transfer sofia/external/mobile@provider to XML[20@default] 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:535 (sofia/external/mobile@provider) State EXECUTE going to sleep 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:472 (sofia/external/mobile@provider) Running State Change CS_ROUTING 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:528 (sofia/external/mobile@provider) State ROUTING 2015-10-26 01:39:27.483860 [DEBUG] mod_sofia.c:123 sofia/external/mobile@provider SOFIA ROUTING 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:166 sofia/external/mobile@provider Standard ROUTING 2015-10-26 01:39:27.483860 [INFO] mod_dialplan_xml.c:635 Processing mobile <mobile>->20 in context default Dialplan: sofia/external/mobile@provider parsing [default->unloop] continue=false Dialplan: sofia/external/mobile@provider Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/mobile@provider Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/external/mobile@provider Absolute Condition [global] Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/external/mobile@provider Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/mobile@provider parsing [default->Local_Extension] continue=false Dialplan: sofia/external/mobile@provider Regex (PASS) [Local_Extension] destination_number(20) =~ /^([2-5][0-9])$/ break=on-false Dialplan: sofia/external/mobile@provider Action export(dialed_extension=20) Dialplan: sofia/external/mobile@provider Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/external/mobile@provider Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/external/mobile@provider Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/external/mobile@provider Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/external/mobile@provider Action set(ringback=%(1000,4000,425)) Dialplan: sofia/external/mobile@provider Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/external/mobile@provider Action set(call_timeout=30) Dialplan: sofia/external/mobile@provider Action set(hangup_after_bridge=true) Dialplan: sofia/external/mobile@provider Action set(continue_on_fail=true) Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/external/mobile@provider Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/external/mobile@provider Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/external/mobile@provider Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/external/mobile@provider Action answer() Dialplan: sofia/external/mobile@provider Action sleep(1000) Dialplan: sofia/external/mobile@provider Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:216 (sofia/external/mobile@provider) State Change CS_ROUTING -> CS_EXECUTE 2015-10-26 01:39:27.483860 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/mobile@provider [BREAK] 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:528 (sofia/external/mobile@provider) State ROUTING going to sleep 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:472 (sofia/external/mobile@provider) Running State Change CS_EXECUTE 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:535 (sofia/external/mobile@provider) State EXECUTE 2015-10-26 01:39:27.483860 [DEBUG] mod_sofia.c:178 sofia/external/mobile@provider SOFIA EXECUTE 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:258 sofia/external/mobile@provider Standard EXECUTE EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-spymap/mobile/0335befe-7b7a-11e5-a603-cb96e1b49eeb) EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-last_dial/mobile/20) EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-last_dial/global/0335befe-7b7a-11e5-a603-cb96e1b49eeb) EXECUTE sofia/external/mobile@provider export(RFC2822_DATE=Mon, 26 Oct 2015 01:39:27 +0100) 2015-10-26 01:39:27.483860 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 26 Oct 2015 01:39:27 +0100] EXECUTE sofia/external/mobile@provider export(dialed_extension=20) 2015-10-26 01:39:27.503879 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [dialed_extension]=[20] EXECUTE sofia/external/mobile@provider bind_meta_app(1 b s execute_extension::dx XML features) 2015-10-26 01:39:27.503879 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/external/mobile@provider bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/mobile.2015-10-26-01-39-27.wav) 2015-10-26 01:39:27.503879 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/mobile.2015-10-26-01-39-27.wav EXECUTE sofia/external/mobile@provider bind_meta_app(3 b s execute_extension::cf XML features) 2015-10-26 01:39:27.503879 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/external/mobile@provider bind_meta_app(4 b s execute_extension::att_xfer XML features) 2015-10-26 01:39:27.503879 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/external/mobile@provider set(ringback=%(1000,4000,425)) 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [ringback]=[%(1000,4000,425)] EXECUTE sofia/external/mobile@provider set(instant_ringback=true) 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [instant_ringback]=[true] EXECUTE sofia/external/mobile@provider set(transfer_ringback=local_stream://moh) 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/external/mobile@provider set(call_timeout=30) 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [call_timeout]=[30] EXECUTE sofia/external/mobile@provider set(hangup_after_bridge=true) 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [hangup_after_bridge]=[true] EXECUTE sofia/external/mobile@provider set(continue_on_fail=true) 2015-10-26 01:39:27.523862 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [continue_on_fail]=[true] EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-call_return/20/mobile) EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-last_dial_ext/20/0335befe-7b7a-11e5-a603-cb96e1b49eeb) EXECUTE sofia/external/mobile@provider set(called_party_callgroup=bakery) 2015-10-26 01:39:27.523862 [DEBUG] mod_dptools.c:1477 sofia/external/mobile@provider SET [called_party_callgroup]=[bakery] EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-last_dial_ext/bakery/0335befe-7b7a-11e5-a603-cb96e1b49eeb) EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-last_dial_ext/global/0335befe-7b7a-11e5-a603-cb96e1b49eeb) EXECUTE sofia/external/mobile@provider hash(insert/192.168.1.5-last_dial/bakery/0335befe-7b7a-11e5-a603-cb96e1b49eeb) EXECUTE sofia/external/mobile@provider bridge(user/20@192.168.1.5) 2015-10-26 01:39:27.523862 [DEBUG] switch_channel.c:1221 sofia/external/mobile@provider EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 26 Oct 2015 01:39:27 +0100] to event 2015-10-26 01:39:27.523862 [DEBUG] switch_channel.c:1221 sofia/external/mobile@provider EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 26 Oct 2015 01:39:27 +0100] to event 2015-10-26 01:39:27.523862 [DEBUG] switch_channel.c:1221 sofia/external/mobile@provider EXPORTING[export_vars] [dialed_extension]=[20] to event 2015-10-26 01:39:27.523862 [DEBUG] switch_ivr_originate.c:2101 Parsing global variables 2015-10-26 01:39:27.543880 [DEBUG] switch_channel.c:1221 sofia/external/mobile@provider EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 26 Oct 2015 01:39:27 +0100] to event 2015-10-26 01:39:27.543880 [DEBUG] switch_channel.c:1221 sofia/external/mobile@provider EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 26 Oct 2015 01:39:27 +0100] to event 2015-10-26 01:39:27.543880 [DEBUG] switch_channel.c:1221 sofia/external/mobile@provider EXPORTING[export_vars] [dialed_extension]=[20] to event 2015-10-26 01:39:27.543880 [DEBUG] switch_ivr_originate.c:2101 Parsing global variables 2015-10-26 01:39:27.543880 [DEBUG] switch_event.c:1698 Parsing variable [sip_invite_domain]=[192.168.1.5] 2015-10-26 01:39:27.543880 [DEBUG] switch_event.c:1698 Parsing variable [presence_id]=[20@192.168.1.5] 2015-10-26 01:39:27.543880 [NOTICE] switch_channel.c:1075 New Channel sofia/internal/20@192.168.1.13:5060 [034101c4-7b7a-11e5-a624-cb96e1b49eeb] 2015-10-26 01:39:27.543880 [DEBUG] mod_sofia.c:4700 (sofia/internal/20@192.168.1.13:5060) State Change CS_NEW -> CS_INIT 2015-10-26 01:39:27.543880 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/20@192.168.1.13:5060 [BREAK] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/20@192.168.1.13:5060) Running State Change CS_INIT 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/20@192.168.1.13:5060) State INIT 2015-10-26 01:39:27.543880 [DEBUG] mod_sofia.c:87 sofia/internal/20@192.168.1.13:5060 SOFIA INIT 2015-10-26 01:39:27.543880 [DEBUG] sofia_glue.c:1241 sofia/internal/20@192.168.1.13:5060 sending invite version: 1.4.23 git 1665168 2015-10-01 18:31:59Z 32bit Local SDP: v=0 o=FreeSWITCH 1445799433 1445799434 IN IP4 192.168.1.5 s=FreeSWITCH c=IN IP4 192.168.1.5 t=0 0 m=audio 20534 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:40 sofia/internal/20@192.168.1.13:5060 Standard INIT 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/20@192.168.1.13:5060) State Change CS_INIT -> CS_ROUTING 2015-10-26 01:39:27.543880 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/20@192.168.1.13:5060 [BREAK] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/20@192.168.1.13:5060) State INIT going to sleep 2015-10-26 01:39:27.543880 [INFO] switch_ivr_originate.c:1193 Sending early media 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/20@192.168.1.13:5060) Running State Change CS_ROUTING 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3595 Set telephone-event payload to 101 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:2506 Set Codec sofia/external/mobile@provider PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2015-10-26 01:39:27.543880 [DEBUG] switch_core_codec.c:111 sofia/external/mobile@provider Original read codec set to PCMA:8 send 1183 bytes to udp/[192.168.1.13]:5060 at 01:39:27.556739: ------------------------------------------------------------------------ INVITE sip:20@192.168.1.13:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.5;rport;branch=z9hG4bK01mvc388g3F4e Max-Forwards: 68 From: "mobile" <sip:mobile@192.168.1.5>;tag=mX9UByt7H37DQ To: <sip:20@192.168.1.13:5060> Call-ID: daa0593a-f61c-1233-8791-b827eb32337b CSeq: 82573919 INVITE Contact: <sip:mod_sofia@192.168.1.5:5060> User-Agent: FreeSWITCH-mod_sofia/1.4.23+git~20151001T183159Z~1665168d37~32bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 221 X-Ecan: On X-FS-Support: update_display,send_info Remote-Party-ID: "mobile" <sip:mobile@192.168.1.5>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1445799433 1445799434 IN IP4 192.168.1.5 s=FreeSWITCH c=IN IP4 192.168.1.5 t=0 0 m=audio 20534 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/20@192.168.1.13:5060) State ROUTING 2015-10-26 01:39:27.543880 [DEBUG] mod_sofia.c:123 sofia/internal/20@192.168.1.13:5060 SOFIA ROUTING 2015-10-26 01:39:27.543880 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/20@192.168.1.13:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2015-10-26 01:39:27.543880 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/20@192.168.1.13:5060 [BREAK] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/20@192.168.1.13:5060) State ROUTING going to sleep 2015-10-26 01:39:27.543880 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/20@192.168.1.13:5060 [BREAK] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/20@192.168.1.13:5060) Running State Change CS_CONSUME_MEDIA 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:3942 Set 2833 dtmf send/recv payload to 101 2015-10-26 01:39:27.543880 [INFO] switch_nat.c:588 NAT port mapping disabled 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:5178 AUDIO RTP [sofia/external/mobile@provider] 192.168.1.5 port 29360 -> xx.xx.xx.xx port 59648 codec: 8 ms: 20 2015-10-26 01:39:27.543880 [DEBUG] sofia.c:6658 Channel sofia/internal/20@192.168.1.13:5060 entering state [calling][0] 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/20@192.168.1.13:5060) State CONSUME_MEDIA 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/20@192.168.1.13:5060) State CONSUME_MEDIA going to sleep 2015-10-26 01:39:27.543880 [DEBUG] switch_rtp.c:3579 Starting timer [soft] 160 bytes per 20ms 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:5476 Set 2833 dtmf send payload to 101 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:5482 Set 2833 dtmf receive payload to 101 2015-10-26 01:39:27.543880 [DEBUG] switch_core_media.c:5504 sofia/external/mobile@provider Set rtp dtmf delay to 40 2015-10-26 01:39:27.543880 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/mobile@provider! 2015-10-26 01:39:27.563871 [DEBUG] switch_channel.c:3419 (sofia/external/mobile@provider) Callstate Change RINGING -> EARLY 2015-10-26 01:39:27.563871 [DEBUG] mod_sofia.c:2264 Ring SDP: v=0 o=FreeSWITCH 1445790607 1445790608 IN IP4 xx.xx.xx.xx s=FreeSWITCH c=IN IP4 ext_ip_addr t=0 0 m=audio 29360 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2015-10-26 01:39:27.563871 [DEBUG] switch_core_session.c:913 Send signal sofia/external/mobile@provider [BREAK] 2015-10-26 01:39:27.563871 [DEBUG] switch_ivr_originate.c:1250 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2015-10-26 01:39:27.563871 [DEBUG] switch_core_codec.c:221 sofia/external/mobile@provider Push codec L16:100 2015-10-26 01:39:27.563871 [DEBUG] switch_ivr_originate.c:1318 Play Ringback Tone [%(1000,4000,425)] send 1067 bytes to udp/[xx.xx.xx.xx]:5060 at 01:39:27.575578: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 62.80.209.30:5060;branch=z9hG4bK-524287-1---f0231a59e0656a3a;rport=5060 From: "mobile"<sip:mobile@provider;user=phone>;tag=b2a8ce1b To: "pstn_did" <sip:pstn_did@siptrunk;user=phone>;tag=gmUjH321ep8jF Call-ID: pSnT7Y8CK7u_vpaaKgC0bw.. CSeq: 1 INVITE Contact: <sip:pstn_did@ext_ip_addr:5080;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.4.23+git~20151001T183159Z~1665168d37~32bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 224 Remote-Party-ID: "pstn_did" <sip:pstn_did@siptrunk>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1445790607 1445790608 IN IP4 ext_ip_addr s=FreeSWITCH c=IN IP4 ext_ip_addr t=0 0 m=audio 29360 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2015-10-26 01:39:27.563871 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/mobile@provider [BREAK] 2015-10-26 01:39:27.583855 [DEBUG] sofia.c:6658 Channel sofia/external/mobile@provider entering state [early][183] recv 370 bytes from udp/[192.168.1.13]:5060 at 01:39:27.628443: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.5;rport=5060;branch=z9hG4bK01mvc388g3F4e From: "mobile" <sip:mobile@192.168.1.5>;tag=mX9UByt7H37DQ To: <sip:20@192.168.1.13:5060>;tag=2174874080 Call-ID: daa0593a-f61c-1233-8791-b827eb32337b CSeq: 82573919 INVITE Contact: <sip:20@192.168.1.13:5060> User-Agent: C530 IP/42.207.00.000.000 Content-Length: 0 ------------------------------------------------------------------------ recv 421 bytes from udp/[192.168.1.13]:5060 at 01:39:28.125276: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.5;rport=5060;branch=z9hG4bK01mvc388g3F4e From: "mobile" <sip:mobile@192.168.1.5>;tag=mX9UByt7H37DQ To: <sip:20@192.168.1.13:5060>;tag=2174874080 Call-ID: daa0593a-f61c-1233-8791-b827eb32337b CSeq: 82573919 INVITE Contact: <sip:20@192.168.1.13:5060> Allow-Events: message-summary, refer, ua-profile User-Agent: C530 IP/42.207.00.000.000 Content-Length: 0 ------------------------------------------------------------------------ 2015-10-26 01:39:28.123847 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/20@192.168.1.13:5060 [BREAK] 2015-10-26 01:39:28.123847 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/20@192.168.1.13:5060 [BREAK] 2015-10-26 01:39:28.123847 [DEBUG] sofia.c:6658 Channel sofia/internal/20@192.168.1.13:5060 entering state [proceeding][180] 2015-10-26 01:39:28.123847 [NOTICE] sofia.c:6760 Ring-Ready sofia/internal/20@192.168.1.13:5060! 2015-10-26 01:39:28.123847 [DEBUG] switch_channel.c:3297 (sofia/internal/20@192.168.1.13:5060) Callstate Change DOWN -> RINGING