I have a Freeswitch install I'm resurrecting from a while back that once worked, but seems to not be anymore. What I wanted to do, to start, is make sure that the machine was working properly.
I fired it up and registered two clients on softphone apps, extensions 1002 and 1003; when I tried to get them to call one another, I got back a 404 error and a "No route, aborting"/NO_ROUTE_DESTINATION message in the logs. Does anyone have any clues? I am pretty much a complete newbie at troubleshooting these sorts of things. Thanks in advance for any help...
My debug log is at the bottom, but first here is what I see when I check sofia status profile external; note that the clients appear and are registered (see below):
=================================================================================================
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 xx.xxx.142.187
SIP-IP xx.xxx.142.187
HOLD-MUSIC local_stream://moh
OUTBOUND-PROXY N/A
CODECS IN iLBC@30i,G7221@32000h,G7221@16000h,G722,PCMU,PCMA,GSM
CODECS OUT iLBC@30i,PCMU,PCMA,GSM
TEL-EVENT 101
DTMF-MODE rfc2833
CNG 13
SESSION-TO 0
MAX-DIALOG 0
NOMEDIA false
LATE-NEG false
PROXY-MEDIA false
AGGRESSIVENAT false
STUN-ENABLED true
STUN-AUTO-DISABLE false
CALLS-IN 19
FAILED-CALLS-IN 19
CALLS-OUT 0
FAILED-CALLS-OUT 0
Registrations:
=================================================================================================
Call-ID: NDc0YWE1YTU1YjJhOTEwMGNmMGMxYjY2N2ZlYzMyMWY.
User: 1003@xx.xxx.142.187
Agent: Zoiper rev.11619
Status: Registered(UDP)(unknown) EXP(2011-12-21 15:50:06) EXPSECS(3038)
Host: fswitch
IP: 72.43.209.146
Port: 5060
Auth-User: 1003
Auth-Realm: xx.xxx.142.187
MWI-Account: 1003@xx.xxx.142.187
Call-ID: PfxBVFYxNIg.pWaY.CpEFO1EhEEqpMHJ
User: 1002@xx.xxx.142.187
Agent: CSipSimple r1108 / vivow-10
Status: Registered(UDP)(unknown) EXP(2011-12-21 15:08:44) EXPSECS(556)
Host: fswitch
IP: 72.43.209.146
Port: 44803
Auth-User: 1002
Auth-Realm: xx.xxx.142.187
MWI-Account: 1002@xx.xxx.142.187
Total items returned: 2
=================================================================================================
2011-12-21 14:53:18.132608 [NOTICE] switch_channel.c:812 New Channel sofia/external/1003@xx.xxx.142.187 [96716f86-500e-445c-8196-59e754c023c0]
2011-12-21 14:53:18.132608 [DEBUG] sofia.c:4659 Channel sofia/external/1003@xx.xxx.142.187 entering state [received][100]
2011-12-21 14:53:18.132608 [DEBUG] sofia.c:4670 Remote SDP:
v=0
o=Z 0 0 IN IP4 192.168.1.108
s=Z
c=IN IP4 192.168.1.108
t=0 0
m=audio 8000 RTP/AVP 3 110 98 8 0 101
a=rtpmap:3 GSM/8000
a=rtpmap:110 speex/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=30
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4504 Audio Codec Compare [GSM:3:8000:20:13200]/[iLBC:97:8000:30:13330]
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4504 Audio Codec Compare [GSM:3:8000:20:13200]/[G7221:115:32000:20:48000]
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4504 Audio Codec Compare [GSM:3:8000:20:13200]/[G7221:107:16000:20:32000]
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4504 Audio Codec Compare [GSM:3:8000:20:13200]/[G722:9:8000:20:64000]
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4504 Audio Codec Compare [GSM:3:8000:20:13200]/[PCMU:0:8000:20:64000]
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4504 Audio Codec Compare [GSM:3:8000:20:13200]/[PCMA:8:8000:20:64000]
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4504 Audio Codec Compare [GSM:3:8000:20:13200]/[GSM:3:8000:20:13200]
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:2757 Set Codec sofia/external/1003@xx.xxx.142.187 GSM/8000 20 ms 160 samples 13200 bits
2011-12-21 14:53:18.132608 [DEBUG] sofia_glue.c:4616 Set 2833 dtmf send/recv payload to 101
2011-12-21 14:53:18.132608 [DEBUG] sofia.c:4837 (sofia/external/1003@xx.xxx.142.187) State Change CS_NEW -> CS_INIT
2011-12-21 14:53:18.132608 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/1003@xx.xxx.142.187 [BREAK]
2011-12-21 14:53:18.132608 [DEBUG] switch_core_state_machine.c:320 (sofia/external/1003@xx.xxx.142.187) Running State Change CS_INIT
2011-12-21 14:53:18.132608 [DEBUG] switch_core_state_machine.c:356 (sofia/external/1003@xx.xxx.142.187) State INIT
2011-12-21 14:53:18.132608 [DEBUG] mod_sofia.c:84 sofia/external/1003@xx.xxx.142.187 SOFIA INIT
2011-12-21 14:53:18.132608 [DEBUG] mod_sofia.c:124 (sofia/external/1003@xx.xxx.142.187) State Change CS_INIT -> CS_ROUTING
2011-12-21 14:53:18.132608 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/1003@xx.xxx.142.187 [BREAK]
2011-12-21 14:53:18.132608 [DEBUG] switch_core_state_machine.c:356 (sofia/external/1003@xx.xxx.142.187) State INIT going to sleep
2011-12-21 14:53:18.132608 [DEBUG] switch_core_state_machine.c:320 (sofia/external/1003@xx.xxx.142.187) Running State Change CS_ROUTING
2011-12-21 14:53:18.134757 [DEBUG] switch_channel.c:1662 (sofia/external/1003@xx.xxx.142.187) Callstate Change DOWN -> RINGING
2011-12-21 14:53:18.134757 [DEBUG] switch_core_state_machine.c:359 (sofia/external/1003@xx.xxx.142.187) State ROUTING
2011-12-21 14:53:18.134757 [DEBUG] mod_sofia.c:147 sofia/external/1003@xx.xxx.142.187 SOFIA ROUTING
2011-12-21 14:53:18.134757 [DEBUG] switch_core_state_machine.c:77 sofia/external/1003@xx.xxx.142.187 Standard ROUTING
2011-12-21 14:53:18.134757 [INFO] mod_dialplan_xml.c:331 Processing 1003 <1003>->1002@xx.xxx.142.187 in context public
Dialplan: sofia/external/1003@xx.xxx.142.187 parsing [public->unloop] continue=false
Dialplan: sofia/external/1003@xx.xxx.142.187 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/1003@xx.xxx.142.187 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/1003@xx.xxx.142.187 parsing [public->public_extensions] continue=false
Dialplan: sofia/external/1003@xx.xxx.142.187 Regex (FAIL) [public_extensions] destination_number(1002@xx.xxx.142.187) =~ /^conf_(.*)$/ break=on-false
Dialplan: sofia/external/1003@xx.xxx.142.187 parsing [public->public_did] continue=false
Dialplan: sofia/external/1003@xx.xxx.142.187 Regex (FAIL) [public_did] destination_number(1002@xx.xxx.142.187) =~ /^(5551212)$/ break=on-false
2011-12-21 14:53:18.134757 [INFO] switch_core_state_machine.c:142 No Route, Aborting
2011-12-21 14:53:18.134757 [DEBUG] switch_channel.c:2540 (sofia/external/1003@xx.xxx.142.187) Callstate Change RINGING -> HANGUP
2011-12-21 14:53:18.134757 [NOTICE] switch_core_state_machine.c:143 Hangup sofia/external/1003@xx.xxx.142.187 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2011-12-21 14:53:18.134757 [DEBUG] switch_channel.c:2556 Send signal sofia/external/1003@xx.xxx.142.187 [KILL]
2011-12-21 14:53:18.134757 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/1003@xx.xxx.142.187 [BREAK]
2011-12-21 14:53:18.134757 [DEBUG] switch_core_state_machine.c:359 (sofia/external/1003@xx.xxx.142.187) State ROUTING going to sleep
2011-12-21 14:53:18.134757 [DEBUG] switch_core_state_machine.c:320 (sofia/external/1003@xx.xxx.142.187) Running State Change CS_HANGUP
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:557 (sofia/external/1003@xx.xxx.142.187) State HANGUP
2011-12-21 14:53:18.136791 [DEBUG] mod_sofia.c:457 Channel sofia/external/1003@xx.xxx.142.187 hanging up, cause: NO_ROUTE_DESTINATION
2011-12-21 14:53:18.136791 [DEBUG] mod_sofia.c:519 Responding to INVITE with: 404
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:46 sofia/external/1003@xx.xxx.142.187 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:557 (sofia/external/1003@xx.xxx.142.187) State HANGUP going to sleep
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:351 (sofia/external/1003@xx.xxx.142.187) State Change CS_HANGUP -> CS_REPORTING
2011-12-21 14:53:18.136791 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/1003@xx.xxx.142.187 [BREAK]
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:320 (sofia/external/1003@xx.xxx.142.187) Running State Change CS_REPORTING
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:617 (sofia/external/1003@xx.xxx.142.187) State REPORTING
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:53 sofia/external/1003@xx.xxx.142.187 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:617 (sofia/external/1003@xx.xxx.142.187) State REPORTING going to sleep
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:345 (sofia/external/1003@xx.xxx.142.187) State Change CS_REPORTING -> CS_DESTROY
2011-12-21 14:53:18.136791 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/1003@xx.xxx.142.187 [BREAK]
2011-12-21 14:53:18.136791 [DEBUG] switch_core_session.c:1288 Session 18 (sofia/external/1003@xx.xxx.142.187) Locked, Waiting on external entities
2011-12-21 14:53:18.136791 [NOTICE] switch_core_session.c:1306 Session 18 (sofia/external/1003@xx.xxx.142.187) Ended
2011-12-21 14:53:18.136791 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/1003@xx.xxx.142.187 [CS_DESTROY]
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:449 (sofia/external/1003@xx.xxx.142.187) Callstate Change HANGUP -> DOWN
2011-12-21 14:53:18.136791 [DEBUG] switch_core_state_machine.c:452 (sofia/external/1003@xx.xxx.142.187) Running State Change CS_DESTROY
2011-12-21 14:53:18.138730 [DEBUG] switch_core_state_machine.c:462 (sofia/external/1003@xx.xxx.142.187) State DESTROY
2011-12-21 14:53:18.138730 [DEBUG] mod_sofia.c:362 sofia/external/1003@xx.xxx.142.187 SOFIA DESTROY
2011-12-21 14:53:18.138730 [DEBUG] switch_core_state_machine.c:60 sofia/external/1003@xx.xxx.142.187 Standard DESTROY
2011-12-21 14:53:18.138730 [DEBUG] switch_core_state_machine.c:462 (sofia/external/1003@xx.xxx.142.187) State DESTROY going to sleep