Slow Mysql Queries

OzSpots - Carl Sawers carl at ozspots.com.au
Tue Jun 7 05:54:47 CEST 2011


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 at 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

---------------------------------------------------------------




More information about the Freeradius-Users mailing list