2.0.2 Radius stop work with Error...
Hello. I use FreeRadius + Postgres for accounting purpose only (avarage 3-5 accounting updates per second). 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
Did anybody now how I can fix that? The only one way to make radius working is start radius with -X (???). -- View this message in context: http://www.nabble.com/2.0.2-Radius-stop-work-with-Error...-tp16046484p160464... Sent from the FreeRadius - User mailing list archive at Nabble.com.
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.
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@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@radacct:# grep ": Acct-U" failure.log | wc -l 59 root@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...-tp16046484p160585... Sent from the FreeRadius - User mailing list archive at Nabble.com.
banga wrote:
After detail debug I have found that sometimes Radius tries to insert more then 50 Updates/sec.
That shouldn't be a problem. I've successfully tested it with 5000 requests per second.
root@radacct:# grep ": Acct-U" failure.log | wc -l 59 root@radacct:#
So it really HI Load.
I'm not sure I agree.
I use next settings: ... Wed Mar 12 05:45:14 2008 : Debug: max_requests_per_server = 8192
Set this to zero.
May be I'm wrong with "thread settings" or it's better to degrease number of SQL sock.
If you decrease the number of SQL sockets, the problem will get worse.
In any case Radius should not die anyway . Isn't it?
Isn't that what I said?
My system : Kernel 2.6.22, 2G RAM, Xeon 2.00 Ghz. Is that parameters enough to process 50-100 SQL updates/sec ?
It should be fine. Alan DeKok.
Alan DeKok-4 wrote:
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.
I use next settings: ... Wed Mar 12 05:45:14 2008 : Debug: max_requests_per_server = 8192
Set this to zero.
Hello. 1) max_requests_per_server = 0 Looks that this setting is better for server, but server again fails after 5 hour of work with the same error : “Error: ]event.c:1946] Failed to insert event” ]event.c:1946] means [event.c:1946] ? :) . Server has 2 Gb RAM and I’m sure that it’s not “out of memory”. May be there some sysctl setting can help server allocate memory a bit better, but 2 Gb looks quite enough. 2) I use –X like solution, it’s work just fine. Then I start radius without –X I see only one process. Is it ok? How I understand it should be at least 30 process because of “start_servers = 30”. I’m I wrong? 3) What do you mean then you write “OR the time on your system stays the same...” How the time can stays the same ? 4) What is incorrect ?? root@:/etc/raddb# check-radiusd-config radiusd: The options -i and -p cannot be used individually. root@:/etc/raddb# # listen { ipaddr = * port = 1813 type = acct } Lokks like this should be ok for radius (I use it only for accounting). With Regards, Banga -- View this message in context: http://www.nabble.com/2.0.2-Radius-stop-work-with-Error...-tp16046484p163490... Sent from the FreeRadius - User mailing list archive at Nabble.com.
banga wrote:
Looks that this setting is better for server, but server again fails after 5 hour of work with the same error : “Error: ]event.c:1946] Failed to insert event”
Try 2.0.3. It looks like the timer on your system doesn't have adequate resolution. (i.e. it's returning the same time for multiple calls). I've committed a fix in 2.0.3 that will avoid this issue.
2) I use –X like solution, it’s work just fine. Then I start radius without –X I see only one process. Is it ok?
Yes.
How I understand it should be at least 30 process because of “start_servers = 30”.
The "-X" means "don't start multiple servers". So... it doesn't start multiple servers.
3) What do you mean then you write “OR the time on your system stays the same...” How the time can stays the same ?
Because of the way the OS implements the "get current time" function.
4) What is incorrect ?? root@:/etc/raddb# check-radiusd-config
Don't run that program. It has been replaced with the "-C" command-line option. See "man radiusd". Alan DeKok.
participants (2)
-
Alan DeKok -
banga