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