[Freeswitch-users] Call is interrupted in 30 seconds, configuring NAT on Amazon EC2

Jurijs Ivolga jurijs.ivolga at gmail.com
Fri Apr 8 19:06:43 MSD 2016


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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20160408/de28daf8/attachment-0001.html 


Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list