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

Fri Apr 8 19:02:09 MSD 2016

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