Good day. I want to continue Dinh Pham Cong topic ((FreeRadius crashed on accounting load tests with 1000 concurrent clients - Tue, 10 Nov 2009 01:39:30 -0800 )) I use freeradius 2.1.9 Linux myhost 2.6.26-2-amd64 Some info from radiusd.conf : -------------- max_request_time = 30 cleanup_delay = 5 max_requests = 2048 hostname_lookups = no allow_core_dumps = yes regular_expressions = yes extended_expressions = yes log { destination = files file = ${logdir}/radius.log syslog_facility = daemon stripped_names = no auth = yes auth_badpass = yes auth_goodpass = yes } checkrad = ${sbindir}/checkrad security { max_attributes = 200 reject_delay = 1 status_server = yes } proxy_requests = no $INCLUDE clients.conf thread pool { start_servers = 5 max_servers = 32 min_spare_servers = 3 max_spare_servers = 10 max_requests_per_server = 0 } -------------- I'm using rlm_sql for my own ippool module: database = "mysql" num_sql_socks = 32 I've started ./radius -xxx -f I've prepared huge file with auth requests for sending: Packet-Type = Access-Request NAS-Identifier = "nas1" User-Name = "test" User-Password = "test" NAS-IP-Address = 212.93.99.126 NAS-Port-Type = Virtual Called-Station-Id = "1000" Calling-Station-Id = "37129111111" Service-Type = Framed-User Framed-Protocol = GPRS-PDP-Context Acct-Session-Id = "d45d637e72d54736" Acct-Multi-Session-Id = "d45d637e396391a1" Packet-Type = Access-Request NAS-Identifier = "nas1" User-Name = "test2" User-Password = "test2" NAS-IP-Address = 212.93.99.126 NAS-Port-Type = Virtual Called-Station-Id = "3" Calling-Station-Id = "37126222222" Service-Type = Framed-User Framed-Protocol = GPRS-PDP-Context Acct-Session-Id = "d45d637e5b97ac8e" Acct-Multi-Session-Id = "d45d637e2dc41c4e" and so on then, I've run radclient: cat auth-det.log |/usr/local/freeradius2.1.9/bin/radclient -c 1 -p 500 -q localhost:1812 auth testkey my module process requests too slow (I will discover this problem in few days, this is mysql-db-cluster issues), but this test causes radiusd segmentation fault. I've grabbed the core and look what it shows: Core was generated by `./radiusd -xxx -f'. Program terminated with signal 11, Segmentation fault. [New process 7173] [New process 7180] [New process 7181] [New process 7182] [New process 7183] [New process 7185] [New process 7187] [New process 7188] [New process 7191] [New process 7193] [New process 7196] [New process 7197] [New process 7174] [New process 7199] [New process 7177] [New process 7202] [New process 7203] [New process 7205] [New process 7176] [New process 7175] [New process 7184] [New process 7186] [New process 7189] [New process 7190] [New process 7192] [New process 7194] [New process 7195] [New process 7198] [New process 7200] [New process 7201] [New process 7204] [New process 7206] [New process 7107] #0 request_pre_handler (request=0xb493fc20) at event.c:1769 1769 if (request->packet->dst_port == 0) { (gdb) bt #0 request_pre_handler (request=0xb493fc20) at event.c:1769 #1 0x0806e404 in radius_handle_request (request=0xb493fc20, fun=0x804ef20 <rad_authenticate>) at event.c:3728 #2 0x08066970 in request_handler_thread (arg=0xae9cbf8) at threads.c:493 #3 0xb780e4c0 in start_thread () from /lib/i686/cmov/libpthread.so.0 #4 0xb75b684e in clone () from /lib/i686/cmov/libc.so.6 And here is last breath of my radius (from radius.log) Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16359 in component module . Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16366 in component module . Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16369 in component module . Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16383 in component module . Tue Sep 14 16:44:43 2010 : Debug: Waking up in 0.1 seconds. Tue Sep 14 16:44:43 2010 : Info: Cleaning up request 16169 ID 189 with timestamp +952 Tue Sep 14 16:44:43 2010 : Info: Child is finally responsive for request 14864 Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16165 in component post-auth module lmtsqlippool1. Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16186 in component post-auth module lmtsqlippool1. Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16189 in component post-auth module lmtsqlippool1. *** Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16241 in component post-auth module lmtsqlippool1. Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16243 in component post-auth module lmtsqlippool1. Tue Sep 14 16:44:43 2010 : Debug: Waking up in 0.1 seconds. Tue Sep 14 16:44:43 2010 : Info: Cleaning up request 16223 ID 21 with timestamp +952 Tue Sep 14 16:44:43 2010 : Debug: Waking up in 0.1 seconds. Tue Sep 14 16:44:43 2010 : Info: Cleaning up request 16173 ID 190 with timestamp +952 Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16165 in component post-auth module lmtsqlippool1. Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16186 in component post-auth module lmtsqlippool1. *** Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16241 in component post-auth module lmtsqlippool1. Tue Sep 14 16:44:43 2010 : Info: WARNING: Child is hung for request 16243 in component post-auth module lmtsqlippool1. Tue Sep 14 16:44:43 2010 : Info: Cleaning up request 16174 ID 151 with timestamp +952 Tue Sep 14 16:44:43 2010 : Debug: Waking up in 0.1 seconds. Tue Sep 14 16:44:43 2010 : Info: Cleaning up request 16177 ID 58 with timestamp +952 Tue Sep 14 16:44:44 2010 : Info: Cleaning up request 16181 ID 60 with timestamp +952 Tue Sep 14 16:44:44 2010 : Debug: rlm_sql_mysql: query: COMMIT Tue Sep 14 16:44:44 2010 : Info: [lmtsqlippool1] expand: UPDATE ippool SET active=1, username=%{Calling-Station-Id} WHERE username=0 AND iprange_id IN (2) LIMIT 1 -> UPDATE ippool SET active=1, username=37126333333 WHERE username=0 AND iprange_id IN (2) LIMIT 1 Tue Sep 14 16:44:44 2010 : Debug: rlm_sql_mysql: query: UPDATE ippool SET active=1, username=37126333333 WHERE username=0 AND iprange_id IN (2) LIMIT 1 Tue Sep 14 16:44:44 2010 : Debug: rlm_sql (sql1): Released sql socket id: 19 Tue Sep 14 16:44:44 2010 : Info: ++++[lmtsqlippool1] returns ok Tue Sep 14 16:44:44 2010 : Info: +++- policy redundant returns ok Tue Sep 14 16:44:44 2010 : Info: ++- else else returns ok Tue Sep 14 16:44:44 2010 : Info: } # server localonly Tue Sep 14 16:44:44 2010 : Info: request 16165 was cancelled. Tue Sep 14 16:44:44 2010 : Info: Finished request 16165. Tue Sep 14 16:44:44 2010 : Debug: Going to the next request Tue Sep 14 16:44:44 2010 : Debug: Thread 1 waiting to be assigned a request Tue Sep 14 16:44:44 2010 : Debug: Thread 1 got semaphore Tue Sep 14 16:44:44 2010 : Debug: Thread 1 handling request 16244, (20 handled so far) Looks like a bug, am I right?