[Freeswitch-users] 480 Temporarily Unavailable/503 Max Sessions (was 502 Bad Gateway: Destination out of order error)

email lists email.list.subscriber at gmail.com
Thu Sep 17 06:33:20 PDT 2009 

Anthony,

I increased the ulimit parameters as suggested.  I then ran into a few
other Freeswitch errors that required me to edit switch.conf.xml to
increase the max sessions, and max sessions per second parameters (to
100000, and 100, respectively).

Now, after a few minutes of running calls at 20 calls per second with
a 3 min. duration, I start seeing an influx of "480 Temporarily
Unavailable" SIP error messages.

Here is a snip of the log:


-------------------------------------------
2009-09-16 19:35:19.18798 [DEBUG] switch_core_session.c:932 Send
signal sofia/external/2015692700 at 72.245.84.150 [BREAK]
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/9726074300 at 72.245.84.24:5060) State HANGUP
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:398
(sofia/external/2015692700 at 72.245.84.150) Running State Change
CS_REPORTING
2009-09-16 19:35:19.18798 [DEBUG] mod_sofia.c:338 Channel
sofia/internal/9726074300 at 72.245.84.24:5060 hanging up, cause:
NORMAL_CLEARING
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:612
(sofia/external/2015692700 at 72.245.84.150) State REPORTING
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:53
sofia/external/2015692700 at 72.245.84.150 Standard REPORTING, cause:
NO_ANSWER
2009-09-16 19:35:19.18798 [DEBUG] mod_sofia.c:417 Responding to INVITE
with: 480
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:612
(sofia/external/2015692700 at 72.245.84.150) State REPORTING going to
sleep
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:411
(sofia/external/2015692700 at 72.245.84.150) State Change CS_REPORTING ->
CS_DESTROY
2009-09-16 19:35:19.18798 [DEBUG] switch_core_session.c:1068 Session
3395 (sofia/external/2015692700 at 72.245.84.150) Locked, Waiting on
external entities
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:46
sofia/internal/9726074300 at 72.245.84.24:5060 Standard HANGUP, cause:
NORMAL_CLEARING
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/9726074300 at 72.245.84.24:5060) State HANGUP going to
sleep
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:434
(sofia/external/2015692915 at 72.245.84.150) State HANGUP
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:46
sofia/external/2015692915 at 72.245.84.150 Standard HANGUP, cause:
NO_ANSWER
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:434
(sofia/external/2015692915 at 72.245.84.150) State HANGUP going to sleep
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/9726074300 at 72.245.84.24:5060) State Change CS_HANGUP
-> CS_REPORTING
2009-09-16 19:35:19.18798 [DEBUG] switch_core_session.c:932 Send
signal sofia/internal/9726074300 at 72.245.84.24:5060 [BREAK]
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/9726074300 at 72.245.84.24:5060) Running State Change
CS_REPORTING
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:612
(sofia/internal/9726074300 at 72.245.84.24:5060) State REPORTING
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:53
sofia/internal/9726074300 at 72.245.84.24:5060 Standard REPORTING, cause:
NORMAL_CLEARING
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:612
(sofia/internal/9726074300 at 72.245.84.24:5060) State REPORTING going to
sleep
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:411
(sofia/internal/9726074300 at 72.245.84.24:5060) State Change
CS_REPORTING -> CS_DESTROY
2009-09-16 19:35:19.18798 [DEBUG] switch_core_session.c:1068 Session
3392 (sofia/internal/9726074300 at 72.245.84.24:5060) Locked, Waiting on
external entities
2009-09-16 19:35:19.18798 [NOTICE] switch_core_session.c:1086 Session
3392 (sofia/internal/9726074300 at 72.245.84.24:5060) Ended
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:434
(sofia/external/2015692915 at 72.245.84.150) State HANGUP
2009-09-16 19:35:19.18798 [NOTICE] switch_core_session.c:1088 Close
Channel sofia/internal/9726074300 at 72.245.84.24:5060 [CS_DESTROY]
2009-09-16 19:35:19.18798 [DEBUG] mod_sofia.c:338 Channel
sofia/external/2015692915 at 72.245.84.150 hanging up, cause: NO_ANSWER
2009-09-16 19:35:19.18798 [DEBUG] mod_sofia.c:406 Sending CANCEL to
sofia/external/2015692915 at 72.245.84.150
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:46
sofia/external/2015692915 at 72.245.84.150 Standard HANGUP, cause:
NO_ANSWER
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:434
(sofia/external/2015692915 at 72.245.84.150) State HANGUP going to sleep
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:564
(sofia/internal/9726074300 at 72.245.84.24:5060) State DESTROY
2009-09-16 19:35:19.18798 [DEBUG] mod_sofia.c:255
sofia/internal/9726074300 at 72.245.84.24:5060 SOFIA DESTROY
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:60
sofia/internal/9726074300 at 72.245.84.24:5060 Standard DESTROY
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:564
(sofia/internal/9726074300 at 72.245.84.24:5060) State DESTROY going to
sleep
2009-09-16 19:35:19.18798 [DEBUG] switch_core_state_machine.c:434
(sofia/internal/2126822269 at 72.245.84.24:5060) State HANGUP
2009-09-16 19:35:19.18798 [DEBUG] mod_sofia.c:338 Channel
sofia/internal/2126822269 at 72.245.84.24:5060 hanging up, cause:
NORMAL_CLEARING
2009-09-16 19:35:19.18798 [DEBUG] mod_sofia.c:417 Responding to INVITE
with: 480
-------------------------------------------


Is there some other limitation on freeswitch I may be hitting?  I
tried throttling down to 10 calls per second (3 min. duration) and
here are some snippets from tailing the log file:


-------------------------------------------
2009-09-16 20:01:47.422656 [DEBUG] switch_ivr_originate.c:2138
Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2009-09-16 20:01:47.496066 [DEBUG] switch_ivr_originate.c:2138
Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2009-09-16 20:01:47.623316 [DEBUG] switch_ivr_originate.c:2138
Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2009-09-16 20:02:59.777664 [CRIT] mod_sofia.c:2601 Error Creating
Session
2009-09-16 20:02:59.777664 [CRIT] mod_sofia.c:2601 Error Creating
Session
2009-09-16 20:02:59.777664 [CRIT] mod_sofia.c:2601 Error Creating
Session
2009-09-16 20:02:59.788134 [CRIT] mod_sofia.c:2601 Error Creating
Session
nta: sent 503 Maximum Calls In Progress for INVITE (1)
nta: sent 503 Maximum Calls In Progress for INVITE (1)
nta: sent 503 Maximum Calls In Progress for INVITE (1)
nta: sent 503 Maximum Calls In Progress for INVITE (1)
nta: sent 502 Bad Gateway for INVITE (1)
nta: sent 502 Bad Gateway for INVITE (1)
nta: sent 502 Bad Gateway for INVITE (1)
nta: sent 503 Maximum Calls In Progress for INVITE (1)
2009-09-16 20:02:59.788134 [CRIT] mod_sofia.c:2601 Error Creating
Session
2009-09-16 20:02:59.788134 [CRIT] mod_sofia.c:2601 Error Creating
Session
2009-09-16 20:02:59.788134 [CRIT] mod_sofia.c:2601 Error Creating
Session
nta: sent 502 Bad Gateway for INVITE (1)
nta: sent 502 Bad Gateway for INVITE (1)
nta: sent 502 Bad Gateway for INVITE (1)
nta: sent 502 Bad Gateway for INVITE (1)
2009-09-16 20:02:59.861110 [CRIT] switch_time.c:500 Over Session Rate
of 100!
nta: sent 480 Temporarily Unavailable for INVITE (1)
nta: sent 480 Temporarily Unavailable for INVITE (1)
nta: sent 480 Temporarily Unavailable for INVITE (1)
nta: sent 480 Temporarily Unavailable for INVITE (1)
nta: sent 480 Temporarily Unavailable for INVITE (1)
nta: sent 480 Temporarily Unavailable for INVITE (1)
-------------------------------------------


I'm going to try increasing the "session rate", but I'm wondering if
there are other limitations I'm running into.

Any thoughts/suggestions?

Vladimir


________________________________________
From: freeswitch-users-bounces at lists.freeswitch.org
[freeswitch-users-bounces at lists.freeswitch.org] On Behalf Of Anthony
Minessale [anthony.minessale at gmail.com]
Sent: Tuesday, September 15, 2009 6:32 PM
To: freeswitch-users at lists.freeswitch.org
Subject: Re: [Freeswitch-users] 502 Bad Gateway: Destination out of
order       error

It's probably from this

2009-09-15 14:34:55.838365 [ERR] sofia_glue.c:2503 AUDIO RTP REPORTS
ERROR: [Socket Error!]
2009-09-15 14:34:55.838365 [NOTICE] sofia_glue.c:2504 Hangup
sofia/external/411 at 192.168.0.150<mailto:411 at 192.168.0.150>
[CS_CONSUME_MEDIA][DESTINATION_OUT_OF_ORDER
]
2009-09-15 14:34:55.838365 [ERR] sofia.c:3796 RTP Error!

your machine failed to produce a socket when requested.

My blind guess, you are on a 32 bit machine and you do not have the
ulimits set for enough file descriptors etc..


ulimit -c unlimited
ulimit -d unlimited
ulimit -f unlimited
ulimit -i unlimited
ulimit -n 999999
ulimit -q unlimited
ulimit -u unlimited
ulimit -v unlimited
ulimit -x unlimited
ulimit -s 244

ulimit -l unlimited


On Tue, Sep 15, 2009 at 5:22 PM, email lists
<email.list.subscriber at gmail.com<mailto:email.list.subscriber at gmail.co
m>> wrote:

Hello All,



Wondering if anyone has experienced this issue before.  I've attached
a snip of the log file where the error occurs and could use some leads
on this.  What's interesting is that the call appears to complete as
normal, and a radius stop message even gets generated, though the
duration is ~1 second.



<snip>

h323-disconnect-time = "h323-disconnect-time=14:35:01.000 UTC Tue Sep
15 2009"

h323-connect-time = "h323-connect-time=14:34:59.000 UTC Tue Sep 15
2009"

</snip>



While there are a lot of pieces involved, the call scenario is pretty
basic (no transfers, no holds, etc.), just a few redirects that
Freeswitch appears to be able to handle without issue.  Attached is a
dumb'd down call ladder.



I tried different rates at which I generate the calls, but it didn't
seem to correlate to the amount of errors I am seeing.



Sending a total of 100 calls, with a call duration of 10 seconds:

@10 calls per second = 14 "502" errors.

@5 calls per second = 4 "502" errors.

@4 calls per second = NO ERRORS (1st run)

@4 calls per second = 39 "502" errors.



Please let me know if any additional information is needed.



Thanks in advance for all help.



Vladimir





_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users at lists.freeswitch.org<mailto:FreeSWITCH-users at lists.fr
eeswitch.org>
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-use
rs
http://www.freeswitch.org




--
Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/
ClueCon http://www.cluecon.com/
Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm
MSN:anthony_minessale at hotmail.com<mailto:MSN%3Aanthony_minessale at hotma
il.com>
GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com<mailto:PAYPAL%3Aanthon
y.minessale at gmail.com>
IRC: irc.freenode.net<http://irc.freenode.net> #freeswitch

FreeSWITCH Developer Conference
sip:888 at conference.freeswitch.org<mailto:sip%3A888 at conference.freeswit
ch.org>
iax:guest at conference.freeswitch.org/888<http://iax:guest@conference.fr
eeswitch.org/888>
googletalk:conf+888 at conference.freeswitch.org<mailto:googletalk%3Aconf
%2B888 at conference.freeswitch.org>
pstn:213-799-1400

More information about the FreeSWITCH-users mailing list