On 06/06/2011 05:05 AM, OzSpots - Carl Sawers wrote:

Thanks Guys,

The slow query log has a lot of entry's in it. It's not obvious which are causing the most issues but I have found a script that was always slowish so have removed it. The line read

# Query_time: 5 Lock_time: 0 Rows_sent: 3 Rows_examined: 17286222

No idea where it thinks there are that may rows...

A script which outputs all the active users from radcheck shows this in the slow query log

# Query_time: 0 Lock_time: 0 Rows_sent: 84 Rows_examined: 32992

Are all the slow query entries potentially a problem, I mean should there be any entries in there at all? While the scripts have changed slightly this DB worked fine on the last server - could it have been corrupted from the sql txt file import perhaps? (via phpadmin)

Regards Carl

Hello Carl, try: "CHECK TABLE <table name>" to check whether it's corrupted */ Drop output from "SHOW CREATE TABLE <table name>" and a sample script which takes a long time to execute here. Best Regards, George Chelidze

Thanks for the advice everyone! I have removed scripts which caused the VERY slow queries and have now had the slow query log on for a few days. It is still showing loads of entry's but http access performance is not noticeably slow(on occasion there is a small delay). The slow queries appear to be mostly coming from radacct and radcheck when a wireless user is trying to authenticate... Phpadmin states that there have been 300000 queries in only 25 hours which is 3 per second. (there is 4 database's including an analytics database also which will be included in this) 20% of the queries are from the 'change db' query. 4300 of the slow queries in the slow query log are from ONE WIRELESS CLIENT trying to authenticate, yet radius.log only shows around 75 authentication attempts...the lines read like this: -------------------------------------- # Time: 110605 13:43:15 # User@Host: freeradius[freeradius] @ localhost [] # Query_time: 0 Lock_time: 0 Rows_sent: 1 Rows_examined: 37 SELECT radacct.UserName AS UserName , radcheck.Value AS Value FROM radacct left outer join radlookupnas ON radlookupnas.user = radacct.UserName AND radlookupnas.macauth = '0' AND radacct.CallingStationId = '60-33-4B-20-1F-5F' left outer join radcheck ON radcheck.username = radacct.username AND radcheck.attribute='User-Password' WHERE radcheck.username = radlookupnas.user LIMIT 1; ------------------------------------- In radius.log I can see that a lot of the entrys are double ups, the same authentication request repeated a few times over 2 or 3 seconds: -------------------------------------- Tue Jun 7 09:31:34 2011 : Auth: Login incorrect: [60-33-4B-20-1F-5F/password] (from client localhost port 3 cli 60-33-4B-20-1F-5F) Tue Jun 7 09:31:35 2011 : Auth: Login incorrect: [60-33-4B-20-1F-5F/password] (from client localhost port 3 cli 60-33-4B-20-1F-5F) Tue Jun 7 09:31:35 2011 : Auth: Login incorrect: [60-33-4B-20-1F-5F/password] (from client localhost port 3 cli 60-33-4B-20-1F-5F) -------------------------------------- AND the occasional Error like this: ----------------------- Error: Discarding duplicate request from client localhost:58813 - ID: 19 due to unfinished request 14831 Error: WARNING: Unresponsive child (id 2954177424) for request 14832 (in component accounting module rlm_sql) Error: Discarding duplicate request from client localhost:33869 - ID: 151 due to unfinished request 14832 --------------------------- PHPmyadmin runtime info states that Select_full_join is 49 and that if this value is not 0, you should carefully check the indexes of your tables. If the radius Mysql tables need to be indexed which ones? radacct has 3500 records and is 1.1mb, radcheck has 9000 and is .5mb and aradacct has 27000 and is 8mb. Are either of these that big? I output this mysqlreport and tried to find where issues are but it's not obvious to me: ----------------------------------------------- MySQL 5.0.51a-3ubuntu5- uptime 0 23:40:19 Tue Jun 7 11:23:18 2011 __ Key _________________________________________________________________ Buffer used 4.71M of 32.00M %Used: 14.71 Current 5.02M %Usage: 15.70 Write hit 23.31% Read hit 99.74% __ Questions ___________________________________________________________ Total 276.17k 3.2/s QC Hits 135.76k 1.6/s %Total: 49.16 Com_ 49.73k 0.6/s 18.01 COM_QUIT 46.82k 0.5/s 16.95 DMS 44.44k 0.5/s 16.09 -Unknown 588 0.0/s 0.21 Slow (4) 7.44k 0.1/s 2.69 %DMS: 16.74 Log: ON DMS 44.44k 0.5/s 16.09 UPDATE 19.94k 0.2/s 7.22 44.87 SELECT 19.70k 0.2/s 7.13 44.33 DELETE 2.13k 0.0/s 0.77 4.79 INSERT 1.69k 0.0/s 0.61 3.80 REPLACE 987 0.0/s 0.36 2.22 Com_ 49.73k 0.6/s 18.01 change_db 46.71k 0.5/s 16.91 show_status 1.14k 0.0/s 0.41 set_option 729 0.0/s 0.26 __ SELECT and Sort _____________________________________________________ Scan 6.48k 0.1/s %SELECT: 32.91 Range 1.17k 0.0/s 5.92 Full join 47 0.0/s 0.24 Range check 0 0/s 0.00 Full rng join 0 0/s 0.00 Sort scan 737 0.0/s Sort range 888 0.0/s Sort mrg pass 10 0.0/s __ Query Cache _________________________________________________________ Memory usage 800.98k of 16.00M %Used: 4.89 Block Fragmnt 14.25% Hits 135.76k 1.6/s Inserts 18.76k 0.2/s Insrt:Prune 18.76k:1 0.2/s Hit:Insert 7.24:1 __ Table Locks _________________________________________________________ Waited 73 0.0/s %Total: 0.13 Immediate 54.91k 0.6/s __ Tables ______________________________________________________________ Open 195 of 512 %Cache: 38.09 Opened 335 0.0/s __ Connections _________________________________________________________ Max used 18 of 100 %Max: 18.00 Total 46.82k 0.5/s __ Created Temp ________________________________________________________ Disk table 410 0.0/s Table 2.19k 0.0/s Size: 32.0M File 26 0.0/s __ Threads _____________________________________________________________ Running 1 of 11 Cached 7 of 16 %Hit: 99.96 Created 18 0.0/s Slow 0 0/s __ Aborted _____________________________________________________________ Clients 0 0/s Connects 7 0.0/s __ Bytes _______________________________________________________________ Sent 50.74M 595.5/s Received 28.46M 333.9/s __ InnoDB Buffer Pool __________________________________________________ Usage 2.33M of 8.00M %Used: 29.10 Read hit 100.00% Pages Free 363 %Total: 70.90 Data 143 27.93 %Drty: 0.00 Misc 6 1.17 Latched 0 0.00 Reads 5.51M 64.7/s From file 99 0.0/s 0.00 Ahead Rnd 5 0.0/s Ahead Sql 0 0/s Writes 6.63k 0.1/s Flushes 2.56k 0.0/s Wait Free 0 0/s __ InnoDB Lock _________________________________________________________ Waits 0 0/s Current 0 Time acquiring Total 0 ms Average 0 ms Max 0 ms __ InnoDB Data, Pages, Rows ____________________________________________ Data Reads 129 0.0/s Writes 5.09k 0.1/s fsync 3.35k 0.0/s Pending Reads 0 Writes 0 fsync 0 Pages Created 1 0.0/s Read 142 0.0/s Written 2.56k 0.0/s Rows Deleted 61 0.0/s Inserted 112 0.0/s Read 1.20M 14.1/s Updated 1.01k 0.0/s ---------------------------------------------------------------

Thanks for the help Fajar, We wish to fix this in house so don't want to pay for a dba BUT we are not getting much closer to the issue though.... I have found that a lot of the tables are actually indexed I just didn't know where to look.

PHPmyadmin runtime info states that  Select_full_join  is 49    and that if this value is not 0, you should carefully check the indexes of your tables.

Good suggestion. Did you do it?

I had a look at PHPmyadmin runtime variables and it shows this in red highlight , as the tables are actually indexed I'm not sure why this is the case... Also in Red are these, I have adjusted some of the values but no joy: Innodb_buffer_pool_reads Opened_Tables Table_locks_waited Handler_read_rnd Handler_read_rnd_next

OzSpots - Carl Sawers wrote:

Thanks for the help Fajar, We wish to fix this in house so don't want to pay for a dba BUT we are not getting much closer to the issue though....

I have found that a lot of the tables are actually indexed I just didn't know where to look.

Ask on a MySQL list. You have customized the queries, such that they no longer work. This is not a problem for FreeRADIUS. This is a problem for a DBA, or for the MySQL list. Alan DeKok.

Hi, is there an option to turn just SQL Errors and warnings on, to be written to disk? We are running 300 to 1000 Auth Requests per second (plus about 2-3000 Acct) In some rare cases, FR seems to ignore the reply attributes, which are comming from the DB. In that cases, we give the user a clean reject. The Reply-Message reports 'no Ticket', which should be reported ony if there is currently no Ticket available. My opinion is, that not FR is ignoring attributes, but SQL is simply not delivering them ... from time to time, possibly by timeouts .... I assume, that FR would recognise it by reporting some timeouts or other errors/warnings, but to get them, I need the debug mode, which is too hard to get written to disk at that transaction rate. Our FR does MySQL redundant loadbalancing via 6 mysqld to a MySQL Cluster with memory tables only. Thanks. Stefan