2.0.2 Radius stop work with Error...

[banga]

Alan DeKok-4 wrote:
> 
> banga wrote:
>> For some reason very often radius stop work.  Every time with the same
>> error. 
>> 
>> Wed Mar 12 18:08:34 2008 : Error: ]event.c:1946] Failed to insert event 
> 
>   That message should only come if the server runs out of memory, OR the
> time on your system stays the same...
> 
>> Did anybody now how I can fix that?
>> 
>> The only one way to make radius working is start radius with -X (???).
> 
>   Hmm... I don't see why that would help.
> 
>   Alan DeKok.
> -
> List info/subscribe/unsubscribe? See
> http://www.freeradius.org/list/users.html
> 
> 
Looks that this is because of HI LOAD and my misunderstanding in "tunning"
of Radius.

After detail debug I have found that sometimes Radius tries to insert more
then 50 Updates/sec.
This is the last messages in radius log before Radius die :


Wed Mar 12 05:47:23 2008 : Debug:       expand: INSERT into radacct
(AcctSessionId, AcctUniqueId, CallingStationId, .........
Wed Mar 12 05:47:23 2008 : Debug: rlm_sql (sql): Reserving sql socket id: 42
Wed Mar 12 05:47:23 2008 : Debug: Threads: total/active/spare threads =
29/13/16
Wed Mar 12 05:47:23 2008 : Debug: Threads: deleting 1 spare out of 6 spares
Wed Mar 12 05:47:23 2008 : Debug: Cleaning up request 32 ID 99 with
timestamp +128
Wed Mar 12 05:47:23 2008 : Debug: Cleaning up request 33 ID 100 with
timestamp +128
Wed Mar 12 05:47:23 2008 : Debug: Cleaning up request 34 ID 101 with
timestamp +128
Wed Mar 12 05:47:23 2008 : Debug: Cleaning up request 35 ID 102 with
timestamp +128
Wed Mar 12 05:47:23 2008 : Debug: Cleaning up request 36 ID 103 with
timestamp +128
Wed Mar 12 05:47:23 2008 : Debug: Cleaning up request 37 ID 104 with
timestamp +128
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Debug: Waking up in 0.1 seconds.
Wed Mar 12 05:47:23 2008 : Error: ]event.c:1946] Failed to insert event

More then that:
root at radacct:# grep ": Acct-U" failure.log
Wed Mar 12 05:47:21 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"d1040ecf26219792".
Wed Mar 12 05:47:21 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"c174b2c604f47ae6".
Wed Mar 12 05:47:21 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"fc4b1110b7b135ba".
Wed Mar 12 05:47:21 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"6d649716d3997349".
Wed Mar 12 05:47:21 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"dded11c824fb11d7".
....
Wed Mar 12 05:47:23 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"dea445efb6536a79".
Wed Mar 12 05:47:23 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"a4e39361eb2ce555".
Wed Mar 12 05:47:23 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-ID =
"9d1613bb69209f1b".
root at radacct:# grep ": Acct-U" failure.log | wc -l
59
root at radacct:#

So it really HI Load.
I use next settings:
Wed Mar 12 05:45:14 2008 : Debug:       num_sql_socks = 50
......
Wed Mar 12 05:45:14 2008 : Debug:  thread pool {
Wed Mar 12 05:45:14 2008 : Debug:       start_servers = 30
Wed Mar 12 05:45:14 2008 : Debug:       max_servers = 64
Wed Mar 12 05:45:14 2008 : Debug:       min_spare_servers = 3
Wed Mar 12 05:45:14 2008 : Debug:       max_spare_servers = 10
Wed Mar 12 05:45:14 2008 : Debug:       max_requests_per_server = 8192
Wed Mar 12 05:45:14 2008 : Debug:       cleanup_delay = 5
Wed Mar 12 05:45:14 2008 : Debug:       max_queue_size = 65536
Wed Mar 12 05:45:14 2008 : Debug:  }

May be I'm wrong with "thread settings" or it's better to degrease number of
SQL sock.
In any case Radius should not die anyway . Isn't it?

My system :
Kernel 2.6.22, 2G RAM, Xeon 2.00 Ghz. 
Is that parameters enough to process 50-100 SQL updates/sec ?

Has anyone solution intunning?
Should I tune my postgres 8.2 first? How?

Thank you.

-- 
View this message in context: http://www.nabble.com/2.0.2-Radius-stop-work-with-Error...-tp16046484p16058580.html
Sent from the FreeRadius - User mailing list archive at Nabble.com.