Terminated / 503 on any gateway

[Moz]

Hi,

Newfies looks great - I like the interface and the newbies install script was perfect.
I've now installed everything and setup some test gateways, but everytime I try and dial out Freeswitch goes from calling to terminated immediately and the gateway at the other end doesn't even see an INVITE from me.
I have tested with two different gateways where no authentication is required and both have the same result.

If I try and add a gateway that does require authentication then I receive "Registration Failed with status Service Unavailable [503]".

It's almost as if there is no outbound route to the IP of the external gateways.

I have tried pinging the gateways from the command line of my box and this works fine.

When I try and make the outbound call the debug shows:
2012-02-10 11:19:02.983491 [DEBUG] switch_ivr_originate.c:1884 Parsing global variables
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [plivo_request_uuid]=[f2524a82-5402-11e1-9630-f23c91df65a8]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [plivo_answer_url]=[http://correctip:8008/api/v1/answercall/]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [plivo_hangup_url]=[http://correctip:8008/api/v1/hangupcall/]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [origination_caller_id_number]=[8888888888]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [bridge_early_media]=[true]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [hangup_after_bridge]=[true]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [plivo_from]=[8888888888]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [plivo_to]=[44*numberremoved*]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [plivo_app]=[true]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [absolute_codec_string]=[SIP]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [originate_timeout]=[1800]
2012-02-10 11:19:02.983491 [DEBUG] switch_event.c:1522 Parsing variable [ignore_early_media]=[true]
2012-02-10 11:19:02.983491 [NOTICE] switch_channel.c:926 New Channel sofia/external/44*numberremoved* [f252d2a4-5402-11e1-ae99-13d8a974b39d]
2012-02-10 11:19:02.983491 [DEBUG] mod_sofia.c:4665 (sofia/external/44*numberremoved*) State Change CS_NEW -> CS_INIT
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:1180 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:362 (sofia/external/44*numberremoved*) Running State Change CS_INIT
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:401 (sofia/external/44*numberremoved*) State INIT
2012-02-10 11:19:02.983491 [DEBUG] mod_sofia.c:85 sofia/external/44*numberremoved* SOFIA INIT
2012-02-10 11:19:02.983491 [DEBUG] mod_sofia.c:125 (sofia/external/44*numberremoved*) State Change CS_INIT -> CS_ROUTING
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:1180 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:401 (sofia/external/44*numberremoved*) State INIT going to sleep
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:362 (sofia/external/44*numberremoved*) Running State Change CS_ROUTING
2012-02-10 11:19:02.983491 [DEBUG] switch_channel.c:1886 (sofia/external/44*numberremoved*) Callstate Change DOWN -> RINGING
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:410 (sofia/external/44*numberremoved*) State ROUTING
2012-02-10 11:19:02.983491 [DEBUG] mod_sofia.c:148 sofia/external/44*numberremoved* SOFIA ROUTING
2012-02-10 11:19:02.983491 [DEBUG] switch_ivr_originate.c:66 (sofia/external/44*numberremoved*) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:1180 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:410 (sofia/external/44*numberremoved*) State ROUTING going to sleep
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:362 (sofia/external/44*numberremoved*) Running State Change CS_CONSUME_MEDIA
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:429 (sofia/external/44*numberremoved*) State CONSUME_MEDIA
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:429 (sofia/external/44*numberremoved*) State CONSUME_MEDIA going to sleep
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:875 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:875 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:875 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:875 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] sofia.c:5524 Channel sofia/external/44*numberremoved* entering state [calling][0]
2012-02-10 11:19:02.983491 [DEBUG] sofia.c:5524 Channel sofia/external/44*numberremoved* entering state [terminated][503]
2012-02-10 11:19:02.983491 [DEBUG] switch_channel.c:2848 (sofia/external/44*numberremoved*) Callstate Change RINGING -> HANGUP
2012-02-10 11:19:02.983491 [NOTICE] sofia.c:6288 Hangup sofia/external/44*numberremoved* [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2012-02-10 11:19:02.983491 [DEBUG] switch_channel.c:2871 Send signal sofia/external/44*numberremoved* [KILL]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:1180 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:362 (sofia/external/44*numberremoved*) Running State Change CS_HANGUP
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:602 (sofia/external/44*numberremoved*) State HANGUP
2012-02-10 11:19:02.983491 [DEBUG] mod_sofia.c:469 Channel sofia/external/44*numberremoved* hanging up, cause: NORMAL_TEMPORARY_FAILURE
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:47 sofia/external/44*numberremoved* Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:602 (sofia/external/44*numberremoved*) State HANGUP going to sleep
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:393 (sofia/external/44*numberremoved*) State Change CS_HANGUP -> CS_REPORTING
2012-02-10 11:19:02.983491 [DEBUG] switch_core_session.c:1180 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:362 (sofia/external/44*numberremoved*) Running State Change CS_REPORTING
2012-02-10 11:19:02.983491 [DEBUG] switch_ivr_originate.c:3364 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2012-02-10 11:19:02.983491 [DEBUG] switch_core_state_machine.c:662 (sofia/external/44*numberremoved*) State REPORTING
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:79 sofia/external/44*numberremoved* Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:662 (sofia/external/44*numberremoved*) State REPORTING going to sleep
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:387 (sofia/external/44*numberremoved*) State Change CS_REPORTING -> CS_DESTROY
2012-02-10 11:19:03.003502 [DEBUG] switch_core_session.c:1180 Send signal sofia/external/44*numberremoved* [BREAK]
2012-02-10 11:19:03.003502 [DEBUG] switch_core_session.c:1380 Session 22 (sofia/external/44*numberremoved*) Locked, Waiting on external entities
2012-02-10 11:19:03.003502 [NOTICE] switch_core_session.c:1398 Session 22 (sofia/external/44*numberremoved*) Ended
2012-02-10 11:19:03.003502 [NOTICE] switch_core_session.c:1400 Close Channel sofia/external/44*numberremoved* [CS_DESTROY]
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:491 (sofia/external/44*numberremoved*) Callstate Change HANGUP -> DOWN
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:494 (sofia/external/44*numberremoved*) Running State Change CS_DESTROY
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:504 (sofia/external/44*numberremoved*) State DESTROY
2012-02-10 11:19:03.003502 [DEBUG] mod_sofia.c:374 sofia/external/44*numberremoved* SOFIA DESTROY
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:86 sofia/external/44*numberremoved* Standard DESTROY
2012-02-10 11:19:03.003502 [DEBUG] switch_core_state_machine.c:504 (sofia/external/44*numberremoved*) State DESTROY going to sleep

Here's an example of a gateway:

<include>
<gateway name="gw1">
<param name="username" value="register:false"/>
<param name="password" value="register:false"/>
<param name="proxy" value="*ipaddressremoved*"/>
<param name="expire-seconds" value="800"/>
<param name="register" value="false"/>
<param name="retry-seconds" value="60"/>
<param name="context" value="public"/>
</gateway>
</include>

[Moz]

I've now fixed this - I rebooted Freeswitch and it worked - I have no idea why it needed a reboot.

To restart I ran fs_cli then type "shutdown restart"
After a few shutdown lines I pressed return and was dropped back onto my normal shell.
I tried re-running fs_cli many times but it couldn't connect of Freeswitch as Freeswitch didn't auto-restart.
To start Freeswitch again type:

cd /usr/loca/freeswitch/bin
./freeswitch

This started freeswitch and I could connect again on fs_cli.

[areski]

Hello,

As per the beginner's guide :

You should now see the Freeswitch CLI, so now reload the Freeswitch configuration with the following command: (tip; Tab auto-completes)

sofia profile external restart reloadxml
When complete, check the trunk has registered with the following command.

sofia status

Change of configuration doesn't take effect if you don't run sofia profile external restart reloadxml

Yours,
/Areski

[Moz]

Change of configuration doesn't take effect if you don't run sofia profile external restart reloadxml

Hi Areski,

Yes I saw that and reloaded many times as I tried different configurations of gateway XMLs. Each time freeswitch re-loaded the gateways and confirmed like "Added gateway 'gw1' to profile 'external'". However this didn't seem to work, only the reboot worked.

Thanks for the help.

Cheers,

Moz