SOLVED Softphone codec problem? Sip error 488- Not Acceptable Here

Status
Not open for further replies.
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
Hey guys, i'm new to freepbx and i'm having a problem getting an extension up and going. I have setup a conference and can call into it and have 2 way audio, so i now everything is working correctly with my gateway/trunk. The problem is when i set up an extension and connect to it with a sip client like zoiper or gs wave, i cannot place or receive any calls. I'm getting 488 Not Acceptable Here as soon as the outgoing call is answered. I've got PCMU and PCMA listed in my global codec list.. not really sure how to troubleshoot this. Here's a sip trace from GS Wave, can also provide some server logs if needed
 
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
here's the server log from a call just like the one in the sip trace above:

Code: 
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:30.997268 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/05@voip.domain.com) State NEW
2018-03-07 21:32:31.097307 [DEBUG] sofia.c:2442 Re-attaching to session ba678910-48af-4237-9464-c237e86b4ffa
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.117257 [DEBUG] sofia.c:9873 sofia/internal/05@voip.domain.com receiving invite from 166.177.123.5:62671 version: 1.6.20 -37-987c9b9 64bit
2018-03-07 21:32:31.117257 [DEBUG] sofia.c:10044 IP 166.177.123.5 Rejected by acl "domains". Falling back to Digest auth.
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] sofia.c:11168 Setting NAT mode based on via received
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] sofia.c:7084 Channel sofia/internal/05@voip.domain.com entering state [received][100]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] sofia.c:7094 Remote SDP:
ba678910-48af-4237-9464-c237e86b4ffa v=0
ba678910-48af-4237-9464-c237e86b4ffa o=05 8000 8000 IN IP4 10.80.136.201
ba678910-48af-4237-9464-c237e86b4ffa s=SIP Call
ba678910-48af-4237-9464-c237e86b4ffa c=IN IP4 10.80.136.201
ba678910-48af-4237-9464-c237e86b4ffa t=0 0
ba678910-48af-4237-9464-c237e86b4ffa m=audio 49744 RTP/AVP 0 8 9 123 2 97 3 18 101
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:0 PCMU/8000
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:8 PCMA/8000
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:9 G722/8000
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:123 opus/48000/2
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:2 G726-32/8000
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:97 iLBC/8000
ba678910-48af-4237-9464-c237e86b4ffa a=fmtp:97 mode=30
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:3 GSM/8000
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:18 G729/8000
ba678910-48af-4237-9464-c237e86b4ffa a=fmtp:18 annexb=no
ba678910-48af-4237-9464-c237e86b4ffa a=rtpmap:101 telephone-event/8000
ba678910-48af-4237-9464-c237e86b4ffa a=fmtp:101 0-15
ba678910-48af-4237-9464-c237e86b4ffa a=rtcp:49745 IN IP4 10.80.136.201
ba678910-48af-4237-9464-c237e86b4ffa a=ptime:20
ba678910-48af-4237-9464-c237e86b4ffa
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:123:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:123:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/05@voip.domain.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_codec.c:111 sofia/internal/05@voip.domain.com Original read codec set to PCMU:0
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_media.c:4767 sofia/internal/05@voip.domain.com Set 2833 dtmf send payload to 101 recv payload to 101
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] sofia.c:7507 (sofia/internal/05@voip.domain.com) State Change CS_NEW -> CS_INIT
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/05@voip.domain.com) Running State Change CS_INIT (Cur 1 Tot 5)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/05@voip.domain.com) State INIT
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] mod_sofia.c:90 sofia/internal/05@voip.domain.com SOFIA INIT
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:40 sofia/internal/05@voip.domain.com Standard INIT
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/05@voip.domain.com) State Change CS_INIT -> CS_ROUTING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/05@voip.domain.com) State INIT going to sleep
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/05@voip.domain.com) Running State Change CS_ROUTING (Cur 1 Tot 5)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_channel.c:2249 (sofia/internal/05@voip.domain.com) Callstate Change DOWN -> RINGING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/05@voip.domain.com) State ROUTING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] mod_sofia.c:143 sofia/internal/05@voip.domain.com SOFIA ROUTING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [DEBUG] switch_core_state_machine.c:236 sofia/internal/05@voip.domain.com Standard ROUTING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.137497 [INFO] mod_dialplan_xml.c:637 Processing 05 <05>->5404963 in context voip.domain.com
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->user_exists] continue=true
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [user_exists] () =~ // break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2018-03-07 21:32:31.177231 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa3ac126c90 Connected.
2018-03-07 21:32:31.177231 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa3ac126c90 released.
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(user_exists=false)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.177231 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [user_exists]=[false]
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->call-direction] continue=true
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com ANTI-Action set(call_direction=local)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->variables] continue=true
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [variables] () =~ // break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action export(origination_callee_id_name=${destination_number})
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->user_record] continue=true
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [user_record] () =~ // break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
2018-03-07 21:32:31.177231 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa3ac126c90 Connected.
2018-03-07 21:32:31.177231 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa3ac126c90 released.
2018-03-07 21:32:31.197229 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa3ac126c90 Connected.
2018-03-07 21:32:31.197229 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa3ac126c90 released.
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(user_record=)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [user_record]=[UNDEF]
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(from_user_exists=true)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [from_user_exists]=[true]
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(from_user_record=)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [from_user_record]=[UNDEF]
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->redial] continue=true
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [redial] destination_number(5404963) =~ /^(redial|\*870)$/ break=on-true
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [redial] () =~ // break=never
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->speed_dial] continue=false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [speed_dial] destination_number(5404963) =~ /^\*0(.*)$/ break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->telnyx.1d10] continue=false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (FAIL) [telnyx.1d10] destination_number(5404963) =~ /^\+?1?(\d{10})$/ break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com parsing [voip.domain.com->telnyx.7d] continue=false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Regex (PASS) [telnyx.7d] destination_number(5404963) =~ /^(\d{7})$/ break=on-false
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(sip_h_X-accountcode=${accountcode})
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(call_direction=outbound)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action unset(call_timeout)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(hangup_after_bridge=true)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(effective_caller_id_name=${outbound_caller_id_name})
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(effective_caller_id_number=${outbound_caller_id_number})
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(inherit_codec=true)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(ignore_display_updates=true)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(callee_id_number=5404963)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action set(continue_on_fail=true)
ba678910-48af-4237-9464-c237e86b4ffa Dialplan: sofia/internal/05@voip.domain.com Action bridge(sofia/gateway/e3d35ec4-3bf3-4343-b5db-f850372ab203/1xxx5404963)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/05@voip.domain.com) State Change CS_ROUTING -> CS_EXECUTE
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/05@voip.domain.com) State ROUTING going to sleep
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/05@voip.domain.com) Running State Change CS_EXECUTE (Cur 1 Tot 5)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/05@voip.domain.com) State EXECUTE
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_sofia.c:198 sofia/internal/05@voip.domain.com SOFIA EXECUTE
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] switch_core_state_machine.c:328 sofia/internal/05@voip.domain.com Standard EXECUTE
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(call_direction=local)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [call_direction]=[local]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com export(origination_callee_id_name=5404963)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[5404963]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(RFC2822_DATE=Wed, 07 Mar 2018 21:32:31 +0000)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [RFC2822_DATE]=[Wed, 07 Mar 2018 21:32:31 +0000]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com hash(insert/voip.domain.com-last_dial/05/5404963)
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(sip_h_X-accountcode=voip.domain.com)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [sip_h_X-accountcode]=[voip.domain.com]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(call_direction=outbound)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [call_direction]=[outbound]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com unset(call_timeout)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1693 UNSET [call_timeout]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(hangup_after_bridge=true)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [hangup_after_bridge]=[true]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(effective_caller_id_name=Bryan)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.197229 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [effective_caller_id_name]=[Bryan]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(effective_caller_id_number=8706926477)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [effective_caller_id_number]=[8706926477]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(inherit_codec=true)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [inherit_codec]=[true]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(ignore_display_updates=true)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [ignore_display_updates]=[true]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(callee_id_number=5404963)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [callee_id_number]=[5404963]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com set(continue_on_fail=true)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] mod_dptools.c:1548 SET sofia/internal/05@voip.domain.com [continue_on_fail]=[true]
ba678910-48af-4237-9464-c237e86b4ffa EXECUTE sofia/internal/05@voip.domain.com bridge(sofia/gateway/e3d35ec4-3bf3-4343-b5db-f850372ab203/1xxx5404963)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] switch_channel.c:1250 sofia/internal/05@voip.domain.com EXPORTING[export_vars] [domain_name]=[voip.domain.com] to event
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] switch_channel.c:1250 sofia/internal/05@voip.domain.com EXPORTING[export_vars] [origination_callee_id_name]=[5404963] to event
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.217232 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1xxx5404963 [0a2e05f3-2cd2-4109-a826-319fc0f86fed]
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] mod_sofia.c:4819 (sofia/external/1xxx5404963) State Change CS_NEW -> CS_INIT
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1xxx5404963) Running State Change CS_INIT (Cur 2 Tot 6)
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1xxx5404963) State INIT
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] mod_sofia.c:90 sofia/external/1xxx5404963 SOFIA INIT
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] sofia_glue.c:1295 sofia/external/1xxx5404963 sending invite version: 1.6.20 -37-987c9b9 64bit
0a2e05f3-2cd2-4109-a826-319fc0f86fed Local SDP:
0a2e05f3-2cd2-4109-a826-319fc0f86fed v=0
0a2e05f3-2cd2-4109-a826-319fc0f86fed o=FreeSWITCH 1520436009 1520436010 IN IP4 <server ip address>
0a2e05f3-2cd2-4109-a826-319fc0f86fed s=FreeSWITCH
0a2e05f3-2cd2-4109-a826-319fc0f86fed c=IN IP4 <server ip address>
0a2e05f3-2cd2-4109-a826-319fc0f86fed t=0 0
0a2e05f3-2cd2-4109-a826-319fc0f86fed m=audio 22342 RTP/AVP 0 8 101 13
0a2e05f3-2cd2-4109-a826-319fc0f86fed a=rtpmap:0 PCMU/8000
0a2e05f3-2cd2-4109-a826-319fc0f86fed a=rtpmap:8 PCMA/8000
0a2e05f3-2cd2-4109-a826-319fc0f86fed a=rtpmap:101 telephone-event/8000
0a2e05f3-2cd2-4109-a826-319fc0f86fed a=fmtp:101 0-16
0a2e05f3-2cd2-4109-a826-319fc0f86fed a=rtpmap:13 CN/8000
0a2e05f3-2cd2-4109-a826-319fc0f86fed a=ptime:20
0a2e05f3-2cd2-4109-a826-319fc0f86fed a=sendrecv
0a2e05f3-2cd2-4109-a826-319fc0f86fed
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:40 sofia/external/1xxx5404963 Standard INIT
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1xxx5404963) State Change CS_INIT -> CS_ROUTING
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1xxx5404963) State INIT going to sleep
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1xxx5404963) Running State Change CS_ROUTING (Cur 2 Tot 6)
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] sofia.c:7084 Channel sofia/external/1xxx5404963 entering state [calling][0]
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1xxx5404963) State ROUTING
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] mod_sofia.c:143 sofia/external/1xxx5404963 SOFIA ROUTING
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_ivr_originate.c:67 (sofia/external/1xxx5404963) State Change CS_ROUTING -> CS_CONSUME_MEDIA
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1xxx5404963) State ROUTING going to sleep
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1xxx5404963) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 6)
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1xxx5404963) State CONSUME_MEDIA
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.217232 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1xxx5404963) State CONSUME_MEDIA going to sleep
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.277265 [DEBUG] sofia.c:7084 Channel sofia/external/1xxx5404963 entering state [calling][0]
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.377265 [DEBUG] sofia.c:7084 Channel sofia/external/1xxx5404963 entering state [proceeding][180]
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.377265 [NOTICE] sofia.c:7192 Ring-Ready sofia/external/1xxx5404963!
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:31.377265 [DEBUG] switch_channel.c:3346 (sofia/external/1xxx5404963) Callstate Change DOWN -> RINGING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.397265 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/internal/05@voip.domain.com!
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.397265 [DEBUG] sofia.c:7084 Channel sofia/internal/05@voip.domain.com entering state [early][180]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:31.397265 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/05@voip.domain.com!
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] sofia.c:6257 Remote Reason: 88
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] sofia.c:7084 Channel sofia/external/1xxx5404963 entering state [terminated][488]
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [NOTICE] sofia.c:8273 Hangup sofia/external/1xxx5404963 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION]
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1xxx5404963) Running State Change CS_HANGUP (Cur 2 Tot 6)
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1xxx5404963) Callstate Change RINGING -> HANGUP
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1xxx5404963) State HANGUP
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] mod_sofia.c:438 Channel sofia/external/1xxx5404963 hanging up, cause: INCOMPATIBLE_DESTINATION
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:60 sofia/external/1xxx5404963 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1xxx5404963) State HANGUP going to sleep
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1xxx5404963) State Change CS_HANGUP -> CS_REPORTING
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1xxx5404963) Running State Change CS_REPORTING (Cur 2 Tot 6)
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1xxx5404963) State REPORTING
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:174 sofia/external/1xxx5404963 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1xxx5404963) State REPORTING going to sleep
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1xxx5404963) State Change CS_REPORTING -> CS_DESTROY
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_session.c:1665 Session 6 (sofia/external/1xxx5404963) Locked, Waiting on external entities
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [INFO] mod_dptools.c:3436 Originate Failed.  Cause: INCOMPATIBLE_DESTINATION
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [NOTICE] switch_core_state_machine.c:385 sofia/internal/05@voip.domain.com has executed the last dialplan instruction, hanging up.
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/05@voip.domain.com [CS_EXECUTE] [NORMAL_CLEARING]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/05@voip.domain.com) State EXECUTE going to sleep
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/05@voip.domain.com) Running State Change CS_HANGUP (Cur 2 Tot 6)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/05@voip.domain.com) Callstate Change RINGING -> HANGUP
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/05@voip.domain.com) State HANGUP
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] mod_sofia.c:432 sofia/internal/05@voip.domain.com Overriding SIP cause 480 with 488 from the other leg
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] mod_sofia.c:438 Channel sofia/internal/05@voip.domain.com hanging up, cause: NORMAL_CLEARING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 488
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:60 sofia/internal/05@voip.domain.com Standard HANGUP, cause: NORMAL_CLEARING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/05@voip.domain.com) State HANGUP going to sleep
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/05@voip.domain.com) State Change CS_HANGUP -> CS_REPORTING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/05@voip.domain.com) Running State Change CS_REPORTING (Cur 2 Tot 6)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/05@voip.domain.com) State REPORTING
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [NOTICE] switch_core_session.c:1683 Session 6 (sofia/external/1xxx5404963) Ended
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/1xxx5404963 [CS_DESTROY]
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1xxx5404963) Running State Change CS_DESTROY (Cur 1 Tot 6)
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1xxx5404963) State DESTROY
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] mod_sofia.c:343 sofia/external/1xxx5404963 SOFIA DESTROY
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:181 sofia/external/1xxx5404963 Standard DESTROY
0a2e05f3-2cd2-4109-a826-319fc0f86fed 2018-03-07 21:32:34.237252 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1xxx5404963) State DESTROY going to sleep
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_state_machine.c:174 sofia/internal/05@voip.domain.com Standard REPORTING, cause: NORMAL_CLEARING
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/05@voip.domain.com) State REPORTING going to sleep
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/05@voip.domain.com) State Change CS_REPORTING -> CS_DESTROY
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_session.c:1665 Session 5 (sofia/internal/05@voip.domain.com) Locked, Waiting on external entities
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [NOTICE] switch_core_session.c:1683 Session 5 (sofia/internal/05@voip.domain.com) Ended
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/05@voip.domain.com [CS_DESTROY]
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/05@voip.domain.com) Running State Change CS_DESTROY (Cur 0 Tot 6)
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/05@voip.domain.com) State DESTROY
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] mod_sofia.c:343 sofia/internal/05@voip.domain.com SOFIA DESTROY
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_state_machine.c:181 sofia/internal/05@voip.domain.com Standard DESTROY
ba678910-48af-4237-9464-c237e86b4ffa 2018-03-07 21:32:34.277241 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/05@voip.domain.com) State DESTROY going to sleep
2018-03-07 21:34:27.497236 [DEBUG] switch_rtp.c:1463  [  zrtp cache]:     Storing ZRTP cache to </var/lib/freeswitch/db/zrtp.dat>...
2018-03-07 21:34:27.497236 [DEBUG] switch_rtp.c:1324 Saving ZRTP cache: OK
2018-03-07 21:49:27.337400 [DEBUG] switch_rtp.c:1463  [  zrtp cache]:     Storing ZRTP cache to </var/lib/freeswitch/db/zrtp.dat>...
2018-03-07 21:49:27.337400 [DEBUG] switch_rtp.c:1324 Saving ZRTP cache: OK
2018-03-07 22:04:27.157249 [DEBUG] switch_rtp.c:1463  [  zrtp cache]:     Storing ZRTP cache to </var/lib/freeswitch/db/zrtp.dat>...
2018-03-07 22:04:27.157249 [DEBUG] switch_rtp.c:1324 Saving ZRTP cache: OK
 
Last edited:
P

phonesimon

Member
Apr 21, 2017
87
16
8
44
One possibility is that the extension you're calling has a set of codecs that doesn't match your PCMU or PCMA (unusual not to include one of these). Another is that the extension is requiring encrypted media (SRTP) which is not being offered.
 
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
Unfortunately i don't think it's either of those, in the sip client i have enabled all supported codecs (PCMU, PCMA, G722, OPUS, G726_32, iLBC, GSM, & G729) and i have tried changing the SRTP settings from disabled, to enabled/not enforced, and required. None has made a difference
 
P

phonesimon

Member
Apr 21, 2017
87
16
8
44
See if you can get logs off the endpoint that is returning the SIP 488. Also grab a SIP trace by going to the fs_cli and "sofia global siptrace on". This will add the SIP packets to your log file and perhaps give more information.
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
Just had a thought, I wonder if you are getting UDP fragmentation, try switching the grandstream wave to TCP
 
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
I tried TCP with only PCMU, same result. I'll get a more detailed log and see if it gives any clues. Thanks guys
 
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
Also, what did you mean by getting a log from the other endpoint? The sip trace I linked to in my first post is from gs wave.. I'm pretty sure the problem is between the extension client (gs wave) and fusionpbx because as I said earlier conferencing is working perfectly when calling in from the outside. Also FWIW Zoiper fails in the same way
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
I understand why, it may be the second leg that is giving the 488
 
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
Is the 2nd leg the part of the connection between the server and the trunk provider?
 
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
oh sure enough, i checked the sip logs on my telnyx's site and it says the 488 is coming from them. I opened a support ticket to see if they can give me any hints. I have a freepbx server set up thru these guys working perfectly, not sure if it's fusionpbx or something i'm just overlooking... i followed telnyx's instructions to set up the gateway so i guess we'll see
 
B

bkcberry

New Member
Jun 16, 2017
14
2
3
36
Well i ended up rebuilding the server and for whatever reason it's working now. Thanks guys

Edit- i think it may have been because external_rtp_ip and external_sip_ip weren't set to the server's public ip address
 
Last edited:
  • Like
Reactions: NBT Teknoloji
Status
Not open for further replies.
Top Bottom