[Freeswitch-users] early media - no ringback
Brian West
brian at freeswitch.org
Mon Oct 26 21:20:29 MSK 2015
Is NAT involved?
On Sun, Oct 25, 2015 at 8:18 PM, Dada P <dada-p at yandex.com> wrote:
> 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 at provider Action transfer(20 XML default)
> 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:216
> (sofia/external/mobile at 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 at provider [BREAK]
> 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:528
> (sofia/external/mobile at provider) State ROUTING going to sleep
> 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:472
> (sofia/external/mobile at provider) Running State Change CS_EXECUTE
> 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:535
> (sofia/external/mobile at provider) State EXECUTE
> 2015-10-26 01:39:27.463856 [DEBUG] mod_sofia.c:178
> sofia/external/mobile at provider SOFIA EXECUTE
> 2015-10-26 01:39:27.463856 [DEBUG] switch_core_state_machine.c:258
> sofia/external/mobile at provider Standard EXECUTE
> EXECUTE sofia/external/mobile at provider set(outside_call=true)
> 2015-10-26 01:39:27.463856 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [outside_call]=[true]
> EXECUTE sofia/external/mobile at 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 at provider set(domain_name=192.168.1.5)
> 2015-10-26 01:39:27.483860 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [domain_name]=[192.168.1.5]
> EXECUTE sofia/external/mobile at provider transfer(20 XML default)
> 2015-10-26 01:39:27.483860 [DEBUG] switch_ivr.c:1856
> (sofia/external/mobile at 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 at provider [BREAK]
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_session.c:913 Send signal
> sofia/external/mobile at provider [BREAK]
> 2015-10-26 01:39:27.483860 [NOTICE] switch_ivr.c:1863 Transfer
> sofia/external/mobile at provider to XML[20 at default]
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:535
> (sofia/external/mobile at provider) State EXECUTE going to sleep
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:472
> (sofia/external/mobile at provider) Running State Change CS_ROUTING
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:528
> (sofia/external/mobile at provider) State ROUTING
> 2015-10-26 01:39:27.483860 [DEBUG] mod_sofia.c:123
> sofia/external/mobile at provider SOFIA ROUTING
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:166
> sofia/external/mobile at 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 at provider parsing [default->unloop]
> continue=false
> Dialplan: sofia/external/mobile at provider Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/external/mobile at provider Regex (PASS) [global]
> ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/
> break=on-false
> Dialplan: sofia/external/mobile at provider Absolute Condition [global]
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-last_dial/global/${uuid})
> Dialplan: sofia/external/mobile at provider Action
> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
> Dialplan: sofia/external/mobile at provider parsing
> [default->Local_Extension] continue=false
> Dialplan: sofia/external/mobile at provider Regex (PASS) [Local_Extension]
> destination_number(20) =~ /^([2-5][0-9])$/ break=on-false
> Dialplan: sofia/external/mobile at provider Action
> export(dialed_extension=20)
> Dialplan: sofia/external/mobile at provider Action bind_meta_app(1 b s
> execute_extension::dx XML features)
> Dialplan: sofia/external/mobile at 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 at provider Action bind_meta_app(3 b s
> execute_extension::cf XML features)
> Dialplan: sofia/external/mobile at provider Action bind_meta_app(4 b s
> execute_extension::att_xfer XML features)
> Dialplan: sofia/external/mobile at provider Action
> set(ringback=%(1000,4000,425))
> Dialplan: sofia/external/mobile at provider Action
> set(transfer_ringback=local_stream://moh)
> Dialplan: sofia/external/mobile at provider Action set(call_timeout=30)
> Dialplan: sofia/external/mobile at provider Action
> set(hangup_after_bridge=true)
> Dialplan: sofia/external/mobile at provider Action set(continue_on_fail=true)
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
> Dialplan: sofia/external/mobile at provider Action
> set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
> var callgroup)})
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-last_dial_ext/global/${uuid})
> Dialplan: sofia/external/mobile at provider Action
> hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
> Dialplan: sofia/external/mobile at provider Action
> bridge(user/${dialed_extension}@${domain_name})
> Dialplan: sofia/external/mobile at provider Action answer()
> Dialplan: sofia/external/mobile at provider Action sleep(1000)
> Dialplan: sofia/external/mobile at 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 at 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 at provider [BREAK]
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:528
> (sofia/external/mobile at provider) State ROUTING going to sleep
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:472
> (sofia/external/mobile at provider) Running State Change CS_EXECUTE
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:535
> (sofia/external/mobile at provider) State EXECUTE
> 2015-10-26 01:39:27.483860 [DEBUG] mod_sofia.c:178
> sofia/external/mobile at provider SOFIA EXECUTE
> 2015-10-26 01:39:27.483860 [DEBUG] switch_core_state_machine.c:258
> sofia/external/mobile at provider Standard EXECUTE
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-spymap/mobile/0335befe-7b7a-11e5-a603-cb96e1b49eeb)
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-last_dial/mobile/20)
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-last_dial/global/0335befe-7b7a-11e5-a603-cb96e1b49eeb)
> EXECUTE sofia/external/mobile at 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 at 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 at 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 at 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 at 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 at 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 at provider set(ringback=%(1000,4000,425))
> 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [ringback]=[%(1000,4000,425)]
> EXECUTE sofia/external/mobile at provider set(instant_ringback=true)
> 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [instant_ringback]=[true]
> EXECUTE sofia/external/mobile at provider
> set(transfer_ringback=local_stream://moh)
> 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET
> [transfer_ringback]=[local_stream://moh]
> EXECUTE sofia/external/mobile at provider set(call_timeout=30)
> 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [call_timeout]=[30]
> EXECUTE sofia/external/mobile at provider set(hangup_after_bridge=true)
> 2015-10-26 01:39:27.503879 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [hangup_after_bridge]=[true]
> EXECUTE sofia/external/mobile at provider set(continue_on_fail=true)
> 2015-10-26 01:39:27.523862 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [continue_on_fail]=[true]
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-call_return/20/mobile)
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-last_dial_ext/20/0335befe-7b7a-11e5-a603-cb96e1b49eeb)
> EXECUTE sofia/external/mobile at provider set(called_party_callgroup=bakery)
> 2015-10-26 01:39:27.523862 [DEBUG] mod_dptools.c:1477
> sofia/external/mobile at provider SET [called_party_callgroup]=[bakery]
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-last_dial_ext/bakery/0335befe-7b7a-11e5-a603-cb96e1b49eeb)
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-last_dial_ext/global/0335befe-7b7a-11e5-a603-cb96e1b49eeb)
> EXECUTE sofia/external/mobile at provider
> hash(insert/192.168.1.5-last_dial/bakery/0335befe-7b7a-11e5-a603-cb96e1b49eeb)
> EXECUTE sofia/external/mobile at provider bridge(user/20 at 192.168.1.5)
> 2015-10-26 01:39:27.523862 [DEBUG] switch_channel.c:1221
> sofia/external/mobile at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.1.5]
> 2015-10-26 01:39:27.543880 [NOTICE] switch_channel.c:1075 New Channel
> sofia/internal/20 at 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 at 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 at 192.168.1.13:5060 [BREAK]
> 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:472
> (sofia/internal/20 at 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 at 192.168.1.13:5060) State INIT
> 2015-10-26 01:39:27.543880 [DEBUG] mod_sofia.c:87 sofia/internal/
> 20 at 192.168.1.13:5060 SOFIA INIT
> 2015-10-26 01:39:27.543880 [DEBUG] sofia_glue.c:1241 sofia/internal/
> 20 at 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 at 192.168.1.13:5060 Standard INIT
> 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:48
> (sofia/internal/20 at 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 at 192.168.1.13:5060 [BREAK]
> 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:512
> (sofia/internal/20 at 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 at 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 at 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 at 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 at 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 at 192.168.1.5>;tag=mX9UByt7H37DQ
> To: <sip:20 at 192.168.1.13:5060>
> Call-ID: daa0593a-f61c-1233-8791-b827eb32337b
> CSeq: 82573919 INVITE
> Contact: <sip:mod_sofia at 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 at 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 at 192.168.1.13:5060) State ROUTING
> 2015-10-26 01:39:27.543880 [DEBUG] mod_sofia.c:123 sofia/internal/
> 20 at 192.168.1.13:5060 SOFIA ROUTING
> 2015-10-26 01:39:27.543880 [DEBUG] switch_ivr_originate.c:67
> (sofia/internal/20 at 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 at 192.168.1.13:5060 [BREAK]
> 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:528
> (sofia/internal/20 at 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 at 192.168.1.13:5060 [BREAK]
> 2015-10-26 01:39:27.543880 [DEBUG] switch_core_state_machine.c:472
> (sofia/internal/20 at 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 at 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 at 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 at 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 at 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 at provider Set rtp dtmf delay to 40
> 2015-10-26 01:39:27.543880 [NOTICE] sofia_media.c:92 Pre-Answer
> sofia/external/mobile at provider!
> 2015-10-26 01:39:27.563871 [DEBUG] switch_channel.c:3419
> (sofia/external/mobile at 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 at provider [BREAK]
> 2015-10-26 01:39:27.563871 [DEBUG] switch_ivr_originate.c:1250 Raw Codec
> Activation Success L16 at 8000hz 1 channel 20ms
> 2015-10-26 01:39:27.563871 [DEBUG] switch_core_codec.c:221
> sofia/external/mobile at 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 at provider;user=phone>;tag=b2a8ce1b
> To: "pstn_did" <sip:pstn_did at siptrunk;user=phone>;tag=gmUjH321ep8jF
> Call-ID: pSnT7Y8CK7u_vpaaKgC0bw..
> CSeq: 1 INVITE
> Contact: <sip:pstn_did at 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 at 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 at provider [BREAK]
> 2015-10-26 01:39:27.583855 [DEBUG] sofia.c:6658 Channel
> sofia/external/mobile at 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 at 192.168.1.5>;tag=mX9UByt7H37DQ
> To: <sip:20 at 192.168.1.13:5060>;tag=2174874080
> Call-ID: daa0593a-f61c-1233-8791-b827eb32337b
> CSeq: 82573919 INVITE
> Contact: <sip:20 at 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 at 192.168.1.5>;tag=mX9UByt7H37DQ
> To: <sip:20 at 192.168.1.13:5060>;tag=2174874080
> Call-ID: daa0593a-f61c-1233-8791-b827eb32337b
> CSeq: 82573919 INVITE
> Contact: <sip:20 at 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 at 192.168.1.13:5060 [BREAK]
> 2015-10-26 01:39:28.123847 [DEBUG] switch_core_session.c:1062 Send signal
> sofia/internal/20 at 192.168.1.13:5060 [BREAK]
> 2015-10-26 01:39:28.123847 [DEBUG] sofia.c:6658 Channel sofia/internal/
> 20 at 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 at 192.168.1.13:5060!
> 2015-10-26 01:39:28.123847 [DEBUG] switch_channel.c:3297 (sofia/internal/
> 20 at 192.168.1.13:5060) Callstate Change DOWN -> RINGING
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
--
*Brian West*
brian at freeswitch.org
*Twitter: @FreeSWITCH , @briankwest*
http://www.freeswitchbook.com
http://www.freeswitchcookbook.com
Got Bugs? Report them here <https://freeswitch.org/jira>! | Reddit:
/r/freeswitch <https://www.reddit.com/r/freeswitch>
*T:*+19184209001 | *F:*+19184209002 | *M:*+1918424WEST (9378)
*iNUM:*+883 5100 1420 9001 | *ISN:*410*543 | *Skype:*briankwest
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20151026/e5405254/attachment-0001.html
Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users
mailing list