[Freeswitch-users] Call is interrupted in 30 seconds, configuring NAT on Amazon EC2
Regis M
regis.freeswitch.org at tornad.net
Fri Apr 8 20:13:01 MSD 2016
99% of the time 30 seconds hangup (or 32seconds) means a NAT problem... or
a response not come back to source...
2016-04-08 17:06 GMT+02:00 Jurijs Ivolga <jurijs.ivolga at gmail.com>:
> Hi,
>
> This is not what I need, please use ngrep:
>
>
> http://jonathanmanning.com/2009/11/17/how-to-sip-capture-using-ngrep-debug-sip-packets/
>
> With kind regards,
>
> Jurijs
>
> On Fri, Apr 8, 2016 at 6:02 PM, Стас Тельнов <stasan89 at gmail.com> wrote:
>
>> Yes, of cause. I hide some ip and real phone numbers.
>> 178.*.*.12 - ip of provider.
>>
>> *On start call:*
>> 2016-04-08 10:47:10.503262 [NOTICE] switch_channel.c:1101 New Channel
>> sofia/external/8 at sip0.MY_DOMAIN.com
>> [c618eafe-fd98-11e5-a353-831849fc41a3]
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_NEW
>> 2016-04-08 10:47:10.503262 [DEBUG] sofia.c:9248 sofia/external/
>> 8 at sip0.MY_DOMAIN.com receiving invite from 172.31.0.169:5060 version:
>> 1.6.6 64bit
>> 2016-04-08 10:47:10.503262 [DEBUG] sofia.c:6760 Channel sofia/external/
>> 8 at sip0.MY_DOMAIN.com entering state [received][100]
>> 2016-04-08 10:47:10.503262 [DEBUG] sofia.c:6770 Remote SDP:
>> v=0
>> o=- 1460126829 1 IN IP4 85.*.*.4
>> s=portsip.com
>> c=IN IP4 52.*.*.177
>> t=0 0
>> m=audio 40082 RTP/AVP 8 101
>> a=rtpmap:8 PCMA/8000
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-16
>> a=nortpproxy:yes
>>
>> 2016-04-08 10:47:10.503262 [DEBUG] sofia.c:7125 (sofia/external/
>> 8 at sip0.MY_DOMAIN.com) State Change CS_NEW -> CS_INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:492
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State NEW
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:516
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:88 sofia/external/
>> 8 at sip0.MY_DOMAIN.com SOFIA INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:40
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:48
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State Change CS_INIT -> CS_ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:516
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State INIT going to sleep
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_channel.c:2247 (sofia/external/
>> 8 at sip0.MY_DOMAIN.com) Callstate Change DOWN -> RINGING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:532
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:141 sofia/external/
>> 8 at sip0.MY_DOMAIN.com SOFIA ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:166
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard ROUTING
>> 2016-04-08 10:47:10.503262 [INFO] mod_dialplan_xml.c:637 Processing 8
>> <8>->7906******* in context public
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com parsing
>> [public->from_opensips] continue=false
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Regex (PASS)
>> [from_opensips] network_addr(172.31.0.169) =~ /^172\.31\.0\.169$/
>> break=on-false
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Action
>> transfer(${destination_number} XML default)
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:216
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State Change CS_ROUTING ->
>> CS_EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:532
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State ROUTING going to sleep
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:539
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:196 sofia/external/
>> 8 at sip0.MY_DOMAIN.com SOFIA EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:258
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard EXECUTE
>> EXECUTE sofia/external/8 at sip0.MY_DOMAIN.com transfer(7906******* XML
>> default)
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_ivr.c:2085 (sofia/external/
>> 8 at sip0.MY_DOMAIN.com) State Change CS_EXECUTE -> CS_ROUTING
>> 2016-04-08 10:47:10.503262 [NOTICE] switch_ivr.c:2092 Transfer
>> sofia/external/8 at sip0.MY_DOMAIN.com to XML[7906*******@default]
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:539
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State EXECUTE going to sleep
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:532
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:141 sofia/external/
>> 8 at sip0.MY_DOMAIN.com SOFIA ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:166
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard ROUTING
>> 2016-04-08 10:47:10.503262 [INFO] mod_dialplan_xml.c:637 Processing 8
>> <8>->7906******* in context default
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com parsing [default->unloop]
>> continue=false
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Regex (PASS) [unloop]
>> ${unroll_loops}(true) =~ /^true$/ break=on-false
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Regex (FAIL) [unloop]
>> ${sip_looped_call}() =~ /^true$/ break=on-false
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com parsing
>> [default->tod_example] continue=true
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Date/Time Match (PASS)
>> [tod_example] break=on-false
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Action set(open=true)
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com parsing
>> [default->outbound_calls_to_freelycall] continue=false
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Regex (PASS)
>> [outbound_calls_to_freelycall] destination_number(7906*******) =~ /^(.+)/
>> break=on-true
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Action
>> set(hangup_after_bridge=true)
>> Dialplan: sofia/external/8 at sip0.MY_DOMAIN.com Action
>> bridge(sofia/gateway/freelycall.com/7906*******)
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:216
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State Change CS_ROUTING ->
>> CS_EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:532
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State ROUTING going to sleep
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:539
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:196 sofia/external/
>> 8 at sip0.MY_DOMAIN.com SOFIA EXECUTE
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:258
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard EXECUTE
>> EXECUTE sofia/external/8 at sip0.MY_DOMAIN.com set(open=true)
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_dptools.c:1498 SET sofia/external/
>> 8 at sip0.MY_DOMAIN.com [open]=[true]
>> EXECUTE sofia/external/8 at sip0.MY_DOMAIN.com set(hangup_after_bridge=true)
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_dptools.c:1498 SET sofia/external/
>> 8 at sip0.MY_DOMAIN.com [hangup_after_bridge]=[true]
>> EXECUTE sofia/external/8 at sip0.MY_DOMAIN.com bridge(sofia/gateway/
>> freelycall.com/7906*******)
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_ivr_originate.c:2128 Parsing
>> global variables
>> 2016-04-08 10:47:10.503262 [NOTICE] switch_channel.c:1101 New Channel
>> sofia/external/7906******* [c619366c-fd98-11e5-a35c-831849fc41a3]
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:4776
>> (sofia/external/7906*******) State Change CS_NEW -> CS_INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/7906*******) Running State Change CS_INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:516
>> (sofia/external/7906*******) State INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:88
>> sofia/external/7906******* SOFIA INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] sofia_glue.c:1257
>> sofia/external/7906******* sending invite version: 1.6.6 64bit
>> Local SDP:
>> v=0
>> o=FreeSWITCH 1460100428 1460100429 IN IP4 52.*.*.198
>> s=FreeSWITCH
>> c=IN IP4 52.*.*.198
>> t=0 0
>> m=audio 26402 RTP/AVP 8 101 13
>> a=rtpmap:8 PCMA/8000
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-16
>> a=rtpmap:13 CN/8000
>> a=ptime:20
>> a=sendrecv
>>
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:40
>> sofia/external/7906******* Standard INIT
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:48
>> (sofia/external/7906*******) State Change CS_INIT -> CS_ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:516
>> (sofia/external/7906*******) State INIT going to sleep
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/7906*******) Running State Change CS_ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] sofia.c:6760 Channel
>> sofia/external/7906******* entering state [calling][0]
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:532
>> (sofia/external/7906*******) State ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] mod_sofia.c:141
>> sofia/external/7906******* SOFIA ROUTING
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_ivr_originate.c:67
>> (sofia/external/7906*******) State Change CS_ROUTING -> CS_CONSUME_MEDIA
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:532
>> (sofia/external/7906*******) State ROUTING going to sleep
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/7906*******) Running State Change CS_CONSUME_MEDIA
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:551
>> (sofia/external/7906*******) State CONSUME_MEDIA
>> 2016-04-08 10:47:10.503262 [DEBUG] switch_core_state_machine.c:551
>> (sofia/external/7906*******) State CONSUME_MEDIA going to sleep
>> 2016-04-08 10:47:17.443282 [DEBUG] sofia.c:6760 Channel
>> sofia/external/7906******* entering state [proceeding][183]
>> 2016-04-08 10:47:17.443282 [DEBUG] sofia.c:6770 Remote SDP:
>> v=0
>> o=root 153112258 153112258 IN IP4 178.*.*.12
>> s=Asterisk PBX 11.11.0
>> c=IN IP4 178.*.*.12
>> t=0 0
>> m=audio 17362 RTP/AVP 8 101
>> a=rtpmap:8 PCMA/8000
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-16
>> a=ptime:20
>>
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4161 Audio Codec
>> Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4216 Audio Codec
>> Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4077 Set
>> telephone-event payload to 101 at 8000
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:2906 Set Codec
>> sofia/external/7906******* PCMA/8000 20 ms 160 samples 64000 bits 1 channels
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_codec.c:111
>> sofia/external/7906******* Original read codec set to PCMA:8
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4429 Set
>> telephone-event payload to 101 at 8000
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4485
>> sofia/external/7906******* Set 2833 dtmf send payload to 101 recv payload
>> to 101
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6033 AUDIO RTP
>> [sofia/external/7906*******] 172.31.22.124 port 26402 -> 178.*.*.12 port
>> 17362 codec: 8 ms: 20
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_rtp.c:3802 Starting timer
>> [soft] 160 bytes per 20ms
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6332
>> sofia/external/7906******* Set 2833 dtmf send payload to 101
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6339
>> sofia/external/7906******* Set 2833 dtmf receive payload to 101
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6362
>> sofia/external/7906******* Set rtp dtmf delay to 40
>> 2016-04-08 10:47:17.443282 [NOTICE] sofia_media.c:92 Pre-Answer
>> sofia/external/7906*******!
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_channel.c:3468
>> (sofia/external/7906*******) Callstate Change DOWN -> EARLY
>> 2016-04-08 10:47:17.443282 [INFO] switch_ivr_originate.c:3557 Sending
>> early media
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4161 Audio Codec
>> Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4216 Audio Codec
>> Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4077 Set
>> telephone-event payload to 101 at 8000
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:2906 Set Codec
>> sofia/external/8 at sip0.MY_DOMAIN.com PCMA/8000 20 ms 160 samples 64000
>> bits 1 channels
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_codec.c:111 sofia/external/
>> 8 at sip0.MY_DOMAIN.com Original read codec set to PCMA:8
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4429 Set
>> telephone-event payload to 101 at 8000
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:4485
>> sofia/external/8 at sip0.MY_DOMAIN.com Set 2833 dtmf send payload to 101
>> recv payload to 101
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6033 AUDIO RTP
>> [sofia/external/8 at sip0.MY_DOMAIN.com] 172.31.22.124 port 30630 ->
>> 52.*.*.177 port 40082 codec: 8 ms: 20
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_rtp.c:3802 Starting timer
>> [soft] 160 bytes per 20ms
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6332
>> sofia/external/8 at sip0.MY_DOMAIN.com Set 2833 dtmf send payload to 101
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6339
>> sofia/external/8 at sip0.MY_DOMAIN.com Set 2833 dtmf receive payload to 101
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_core_media.c:6362
>> sofia/external/8 at sip0.MY_DOMAIN.com Set rtp dtmf delay to 40
>> 2016-04-08 10:47:17.443282 [NOTICE] sofia_media.c:92 Pre-Answer
>> sofia/external/8 at sip0.MY_DOMAIN.com!
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_channel.c:3468 (sofia/external/
>> 8 at sip0.MY_DOMAIN.com) Callstate Change RINGING -> EARLY
>> 2016-04-08 10:47:17.443282 [DEBUG] mod_sofia.c:2330 Ring SDP:
>> v=0
>> o=FreeSWITCH 1460096207 1460096208 IN IP4 52.*.*.198
>> s=FreeSWITCH
>> c=IN IP4 52.*.*.198
>> t=0 0
>> m=audio 30630 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
>>
>> 2016-04-08 10:47:17.443282 [DEBUG] sofia.c:6760 Channel sofia/external/
>> 8 at sip0.MY_DOMAIN.com entering state [early][183]
>> 2016-04-08 10:47:17.443282 [DEBUG] switch_ivr_originate.c:3608 Originate
>> Resulted in Success: [sofia/external/7906*******]
>> 2016-04-08 10:47:17.463254 [DEBUG] switch_ivr_bridge.c:1591
>> (sofia/external/7906*******) State Change CS_CONSUME_MEDIA ->
>> CS_EXCHANGE_MEDIA
>> 2016-04-08 10:47:17.463254 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/7906*******) Running State Change CS_EXCHANGE_MEDIA
>> 2016-04-08 10:47:17.463254 [DEBUG] switch_core_state_machine.c:542
>> (sofia/external/7906*******) State EXCHANGE_MEDIA
>> 2016-04-08 10:47:17.463254 [DEBUG] mod_sofia.c:613 SOFIA EXCHANGE_MEDIA
>> 2016-04-08 10:47:17.503264 [DEBUG] switch_rtp.c:6654 Correct audio
>> ip/port confirmed.
>> 2016-04-08 10:47:17.663261 [DEBUG] switch_rtp.c:6654 Correct audio
>> ip/port confirmed.
>> 2016-04-08 10:47:21.323279 [DEBUG] sofia.c:6760 Channel
>> sofia/external/7906******* entering state [completing][200]
>> 2016-04-08 10:47:21.323279 [DEBUG] sofia.c:6767 Duplicate SDP
>> v=0
>> o=root 153112258 153112258 IN IP4 178.*.*.12
>> s=Asterisk PBX 11.11.0
>> c=IN IP4 178.*.*.12
>> t=0 0
>> m=audio 17362 RTP/AVP 8 101
>> a=rtpmap:8 PCMA/8000
>> a=rtpmap:101 telephone-event/8000
>> a=fmtp:101 0-16
>> a=ptime:20
>>
>> 2016-04-08 10:47:21.323279 [DEBUG] sofia.c:6760 Channel
>> sofia/external/7906******* entering state [ready][200]
>> 2016-04-08 10:47:21.323279 [NOTICE] sofia.c:7665 Channel
>> [sofia/external/7906*******] has been answered
>> 2016-04-08 10:47:21.323279 [DEBUG] switch_channel.c:3767
>> (sofia/external/7906*******) Callstate Change EARLY -> ACTIVE
>> 2016-04-08 10:47:21.323279 [DEBUG] mod_sofia.c:799 Local SDP
>> sofia/external/8 at sip0.MY_DOMAIN.com:
>> v=0
>> o=FreeSWITCH 1460096207 1460096209 IN IP4 52.*.*.198
>> s=FreeSWITCH
>> c=IN IP4 52.*.*.198
>> t=0 0
>> m=audio 30630 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
>>
>> 2016-04-08 10:47:21.323279 [DEBUG] sofia.c:6760 Channel sofia/external/
>> 8 at sip0.MY_DOMAIN.com entering state [completed][200]
>> 2016-04-08 10:47:21.323279 [NOTICE] switch_ivr_bridge.c:616 Channel
>> [sofia/external/8 at sip0.MY_DOMAIN.com] has been answered
>> 2016-04-08 10:47:21.323279 [DEBUG] switch_channel.c:3767 (sofia/external/
>> 8 at sip0.MY_DOMAIN.com) Callstate Change EARLY -> ACTIVE
>> 2016-04-08 10:47:21.383279 [DEBUG] switch_rtp.c:6654 Correct audio
>> ip/port confirmed.
>> 2016-04-08 10:47:21.423259 [DEBUG] switch_rtp.c:6654 Correct audio
>> ip/port confirmed.
>>
>>
>> *And after 30 seconds:*
>> 2016-04-08 10:47:53.343283 [DEBUG] sofia.c:6760 Channel sofia/external/
>> 8 at sip0.MY_DOMAIN.com entering state [terminating][0]
>> 2016-04-08 10:47:53.343283 [NOTICE] sofia.c:7779 Hangup sofia/external/
>> 8 at sip0.MY_DOMAIN.com [CS_EXECUTE] [NORMAL_UNSPECIFIED]
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_ivr_bridge.c:699 sofia/external/
>> 8 at sip0.MY_DOMAIN.com ending bridge by request from write function
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD
>> DONE [sofia/external/7906*******]
>> 2016-04-08 10:47:53.343283 [NOTICE] switch_ivr_bridge.c:881 Hangup
>> sofia/external/7906******* [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:542
>> (sofia/external/7906*******) State EXCHANGE_MEDIA going to sleep
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/7906*******) Running State Change CS_HANGUP
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:739
>> (sofia/external/7906*******) Callstate Change ACTIVE -> HANGUP
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:741
>> (sofia/external/7906*******) State HANGUP
>> 2016-04-08 10:47:53.343283 [DEBUG] mod_sofia.c:431 Channel
>> sofia/external/7906******* hanging up, cause: NORMAL_CLEARING
>> 2016-04-08 10:47:53.343283 [DEBUG] mod_sofia.c:484 Sending BYE to
>> sofia/external/7906*******
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:60
>> sofia/external/7906******* Standard HANGUP, cause: NORMAL_CLEARING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:741
>> (sofia/external/7906*******) State HANGUP going to sleep
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:508
>> (sofia/external/7906*******) State Change CS_HANGUP -> CS_REPORTING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/7906*******) Running State Change CS_REPORTING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:827
>> (sofia/external/7906*******) State REPORTING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:104
>> sofia/external/7906******* Standard REPORTING, cause: NORMAL_CLEARING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:827
>> (sofia/external/7906*******) State REPORTING going to sleep
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:499
>> (sofia/external/7906*******) State Change CS_REPORTING -> CS_DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_session.c:1646 Session 2
>> (sofia/external/7906*******) Locked, Waiting on external entities
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_ivr_bridge.c:705 sofia/external/
>> 8 at sip0.MY_DOMAIN.com ending bridge by request from read function
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD
>> DONE [sofia/external/8 at sip0.MY_DOMAIN.com]
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_ivr_bridge.c:1692
>> sofia/external/8 at sip0.MY_DOMAIN.com skip receive message [UNBRIDGE]
>> (channel is hungup already)
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_session.c:2796
>> sofia/external/8 at sip0.MY_DOMAIN.com skip receive message
>> [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:539
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State EXECUTE going to sleep
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_HANGUP
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:739
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Callstate Change ACTIVE -> HANGUP
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:741
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State HANGUP
>> 2016-04-08 10:47:53.343283 [DEBUG] mod_sofia.c:431 Channel sofia/external/
>> 8 at sip0.MY_DOMAIN.com hanging up, cause: NORMAL_UNSPECIFIED
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:60
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard HANGUP, cause:
>> NORMAL_UNSPECIFIED
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:741
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State HANGUP going to sleep
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:508
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State Change CS_HANGUP ->
>> CS_REPORTING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:473
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_REPORTING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:827
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State REPORTING
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:104
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard REPORTING, cause:
>> NORMAL_UNSPECIFIED
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:827
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State REPORTING going to sleep
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:499
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State Change CS_REPORTING ->
>> CS_DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_session.c:1646 Session 1
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Locked, Waiting on external
>> entities
>> 2016-04-08 10:47:53.343283 [NOTICE] switch_core_session.c:1664 Session 1
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Ended
>> 2016-04-08 10:47:53.343283 [NOTICE] switch_core_session.c:1668 Close
>> Channel sofia/external/8 at sip0.MY_DOMAIN.com [CS_DESTROY]
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:630
>> (sofia/external/8 at sip0.MY_DOMAIN.com) Running State Change CS_DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:640
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] mod_sofia.c:341 sofia/external/
>> 8 at sip0.MY_DOMAIN.com SOFIA DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:111
>> sofia/external/8 at sip0.MY_DOMAIN.com Standard DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:640
>> (sofia/external/8 at sip0.MY_DOMAIN.com) State DESTROY going to sleep
>> 2016-04-08 10:47:53.343283 [NOTICE] switch_core_session.c:1664 Session 2
>> (sofia/external/7906*******) Ended
>> 2016-04-08 10:47:53.343283 [NOTICE] switch_core_session.c:1668 Close
>> Channel sofia/external/7906******* [CS_DESTROY]
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:630
>> (sofia/external/7906*******) Running State Change CS_DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:640
>> (sofia/external/7906*******) State DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] mod_sofia.c:341
>> sofia/external/7906******* SOFIA DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:111
>> sofia/external/7906******* Standard DESTROY
>> 2016-04-08 10:47:53.343283 [DEBUG] switch_core_state_machine.c:640
>> (sofia/external/7906*******) State DESTROY going to sleep
>>
>>
>> 2016-04-08 17:37 GMT+03:00 Jurijs Ivolga <jurijs.ivolga at gmail.com>:
>>
>>> Hi,
>>>
>>> I would recommend you to capture SIP packets during call on Freeswitch
>>> server and send it here, I will take a look on it.
>>>
>>> With kind regards,
>>>
>>> Jurijs
>>>
>>> On Fri, Apr 8, 2016 at 5:34 PM, Стас Тельнов <stasan89 at gmail.com> wrote:
>>>
>>>> I already tried disabling timers, does not work.
>>>>
>>>> 2016-04-08 17:19 GMT+03:00 Oleg Stolyar <olegstolyar at gmail.com>:
>>>>
>>>>> Try disabling session timers in the sip profile. I think that line is
>>>>> commented out by default, so uncomment it.
>>>>>
>>>>> <param name="enable-timer" value="false"/>
>>>>>
>>>>> On Fri, Apr 8, 2016 at 6:59 AM, Стас Тельнов <stasan89 at gmail.com>
>>>>> wrote:
>>>>>
>>>>>> Hello.
>>>>>>
>>>>>> When using a call or conference through sip — freeswitch with
>>>>>> external provider there is a problem – the call is interrupted in 30
>>>>>> seconds. Though the sound goes all right.
>>>>>> I think that it caused by the NAT settings for freeswitch, but I
>>>>>> don't understand how to adjust it correctly.
>>>>>> At start of freeswitch I see the following mistakes in the tracking
>>>>>> data:
>>>>>> 2016-04-08 07:04:50.903529 [INFO] switch_nat.c:417 Scanning for NAT
>>>>>> 2016-04-08 07:04:50.903678 [DEBUG] switch_nat.c:170 Checking for PMP
>>>>>> 1/5
>>>>>> 2016-04-08 07:04:51.903843 [DEBUG] switch_nat.c:170 Checking for PMP
>>>>>> 2/5
>>>>>> 2016-04-08 07:04:52.904023 [DEBUG] switch_nat.c:170 Checking for PMP
>>>>>> 3/5
>>>>>> 2016-04-08 07:04:53.904185 [DEBUG] switch_nat.c:170 Checking for PMP
>>>>>> 4/5
>>>>>> 2016-04-08 07:04:54.904360 [DEBUG] switch_nat.c:170 Checking for PMP
>>>>>> 5/5
>>>>>> 2016-04-08 07:04:55.904495 [ERR] switch_nat.c:199 Error checking for
>>>>>> PMP [general error]
>>>>>> 2016-04-08 07:04:55.904548 [DEBUG] switch_nat.c:422 Checking for UPnP
>>>>>> 2016-04-08 07:05:07.905219 [INFO] switch_nat.c:438 No PMP or UPnP NAT
>>>>>> devices detected!
>>>>>>
>>>>>> Despite of this mistake, conference communication between two
>>>>>> internal users works normally. The problem arises at a call through
>>>>>> external provider.
>>>>>>
>>>>>> We have the following architecture:
>>>>>> In a cloud of Amazon EC2 there are 2 servers – opensips and
>>>>>> freeswitch, both for NAT for external clients, but have an opportunity to
>>>>>> work with each other directly.
>>>>>> opensips has the internal address 172.31.0.169 and external 52.
>>>>>> *.*.177
>>>>>> freeswitch has the internal address 172.31.22.124 and external 52.
>>>>>> *.*.198
>>>>>>
>>>>>> In fact, freeswitch acts only for conferences, and is ready for use
>>>>>> of a remote DB on opensips.
>>>>>> The auto-nat settings by default didn't work. The problem is in the
>>>>>> external profile settings as far as I understand.
>>>>>>
>>>>>> I have filled and created the following configuration:
>>>>>> vars.xml
>>>>>> <X-PRE-PROCESS cmd="set" data="bind_server_ip=auto”/>
>>>>>> <X-PRE-PROCESS cmd="set" data="external_rtp_ip=52.*.*.198”/> <!—
>>>>>> public freeswitch ip —>
>>>>>> <X-PRE-PROCESS cmd="set" data="external_sip_ip=52.*.*.198”/> <!—
>>>>>> public freeswitch ip —>
>>>>>> <!-- External SIP Profile -->
>>>>>> <X-PRE-PROCESS cmd="set" data="external_auth_calls=true"/>
>>>>>> <X-PRE-PROCESS cmd="set" data="external_sip_port=5060"/>
>>>>>> <X-PRE-PROCESS cmd="set" data="external_tls_port=5061"/>
>>>>>> <X-PRE-PROCESS cmd="set" data="external_ssl_enable=true"/>
>>>>>> <X-PRE-PROCESS cmd="set"
>>>>>> data="external_ssl_dir=$${base_dir}/conf/tls"/>
>>>>>>
>>>>>> sip_profile/external.xml
>>>>>> <param name="rtp-ip" value="$${local_ip_v4}"/>
>>>>>> <param name="sip-ip" value="$${local_ip_v4}"/>
>>>>>>
>>>>>> <param name="ext-rtp-ip" value=“52.*.*.198”/> <!— public
>>>>>> freeswitch ip —>
>>>>>> <param name="ext-sip-ip" value=“52.*.*.198”/> <!— public
>>>>>> freeswitch ip —>
>>>>>> In this sip_profile/external.xml I tried to fill rtp-ip/sip-ip and
>>>>>> ext-rtp-ip/ext-sip-ip with the corresponding addresses of opensips server
>>>>>> (that would be logical), but in that case conferences didn't work at all
>>>>>> and errors below appeared:
>>>>>> [ERR] sofia.c:2935 Error Creating SIP UA for profile: external ...
>>>>>> Also I tried to put such configuration:
>>>>>> <param name="rtp-ip" value="auto"/>
>>>>>> <param name="sip-ip" value="52.*.*.198”/>
>>>>>> but it also hasn't helped to solve the problem.
>>>>>>
>>>>>> autoload_configs/switch.conf.xml
>>>>>> <param name="rtp-start-port" value="16384"/>
>>>>>> <param name="rtp-end-port" value="32768"/>
>>>>>>
>>>>>> "sofia status" looks as follows:
>>>>>> Name Type
>>>>>> Data State
>>>>>>
>>>>>> =================================================================================================
>>>>>> 172.31.22.124 alias
>>>>>> internal ALIASED
>>>>>> external profile sip:mod_sofia at 52.*.*.198:5060
>>>>>> RUNNING (0)
>>>>>> external profile sip:mod_sofia at 52.*.*.198:5061
>>>>>> RUNNING (0) (TLS)
>>>>>> external::*********.com gateway sip:USER@*********.com
>>>>>> REGED
>>>>>> internal profile sip:mod_sofia at 52.*.*.198:5080
>>>>>> RUNNING (0)
>>>>>> internal profile sip:mod_sofia at 52.*.*.198:5081
>>>>>> RUNNING (0) (TLS)
>>>>>>
>>>>>> =================================================================================================
>>>>>> 2 profiles 1 alias
>>>>>>
>>>>>> "sofia status profile external" looks as follows:
>>>>>>
>>>>>> =================================================================================================
>>>>>> Name external
>>>>>> Domain Name N/A
>>>>>> Auto-NAT false
>>>>>> DBName sofia_reg_external
>>>>>> Pres Hosts
>>>>>> Dialplan XML
>>>>>> Context public
>>>>>> Challenge Realm auto_to
>>>>>> RTP-IP 172.31.22.124
>>>>>> Ext-RTP-IP 52.*.*.198
>>>>>> SIP-IP 172.31.22.124
>>>>>> Ext-SIP-IP 52.*.*.198
>>>>>> URL sip:mod_sofia at 52.*.*.198:5060
>>>>>> BIND-URL sip:mod_sofia at 52.
>>>>>> *.*.198:5060;maddr=172.31.22.124;transport=udp,tcp
>>>>>> TLS-URL sip:mod_sofia at 52.*.*.198:5061
>>>>>> TLS-BIND-URL sips:mod_sofia at 52.
>>>>>> *.*.198:5061;maddr=172.31.22.124;transport=tls
>>>>>> HOLD-MUSIC local_stream://moh
>>>>>> OUTBOUND-PROXY N/A
>>>>>> CODECS IN PCMA
>>>>>> CODECS OUT PCMA
>>>>>> TEL-EVENT 101
>>>>>> DTMF-MODE rfc2833
>>>>>> CNG 13
>>>>>> SESSION-TO 0
>>>>>> MAX-DIALOG 0
>>>>>> NOMEDIA false
>>>>>> LATE-NEG true
>>>>>> PROXY-MEDIA false
>>>>>> ZRTP-PASSTHRU true
>>>>>> AGGRESSIVENAT false
>>>>>> CALLS-IN 0
>>>>>> FAILED-CALLS-IN 0
>>>>>> CALLS-OUT 0
>>>>>> FAILED-CALLS-OUT 0
>>>>>> REGISTRATIONS 0
>>>>>>
>>>>>>
>>>>>>
>>>>>> What do I adjust wrong? Whether there is some opportunity, to tell
>>>>>> freeswitch not to break off a call in 30 seconds even if NAT isn't adjusted?
>>>>>>
>>>>>>
>>>>>> _________________________________________________________________________
>>>>>> 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
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>> _________________________________________________________________________
>>>>> 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
>>>>>
>>>>
>>>>
>>>>
>>>> _________________________________________________________________________
>>>> 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
>>>>
>>>
>>>
>>> _________________________________________________________________________
>>> 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
>>>
>>
>>
>> _________________________________________________________________________
>> 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
>>
>
>
> _________________________________________________________________________
> 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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20160408/ab605055/attachment-0001.html
Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users
mailing list