Queries for permission checks are slow in large sites
Description
Attachments
- 17 May 2013, 12:21 PM
- 03 May 2013, 01:52 PM
Activity
Matthew Buckett October 10, 2013 at 11:27 AM
Do you have a link to the MySQL forums discussion?
Aaron Zeckoski October 10, 2013 at 10:13 AM
We think that upgrading to a new version of MySQL 5.5+ will likely solve this issue so we'll leave the patch for people who want to keep running mysql 5.1 but we won't apply it to the kernel because it is likely to actually hurt performance for people who did upgrade (as per the advice of the mysql forums).
Matthew Buckett May 17, 2013 at 12:25 PM
The strange thing is from the explain we should be looking at more rows with the force index, but it seems to work out faster....
Matthew Buckett May 17, 2013 at 12:21 PM
Ok, so I have a site locally that has 13527 users in it. Looking at the count query, when it's not in the query cache:
optimizer: 0.069 sec
force index: 0.019 sec
This is reasonably reproduceable, by changing the userId you can avoid the query cache. We're on MySQL 5.1.66 from Debian squeeze.
I've attached the explains against our live DB as HTML.
SELECT count:yellow_star: FROM SAKAI_REALM;
SELECT count:yellow_star: FROM SAKAI_REALM_ROLE;
SELECT count:yellow_star: FROM SAKAI_REALM_RL_GR;
SELECT count:yellow_star: FROM SAKAI_REALM_RL_FN;
SELECT count:yellow_star: FROM SAKAI_REALM_FUNCTION;
SAKAI_REALM: 76253
SAKAI_REALM_ROLE: 39
SAKAI_REALM_RL_GR: 551716
SAKAI_REALM_RL_FN: 7509053
SAKAI_REALM_FUNCTION: 258
Stephen Marquard May 16, 2013 at 3:08 PMEdited
Here are the table sizes in our production db (rows):
SAKAI_REALM: 158680
SAKAI_REALM_ROLE: 40
SAKAI_REALM_RL_GR: 2582045
SAKAI_REALM_RL_FN: 35800127
SAKAI_REALM_FUNCTION: 297
Our production mysql is 5.1.68
This is from our slow query log from a period last year (running 2.8), output from mysqldumpslow -s=t -t 15
Count: 15341 Time=5.00s (76760s) Lock=0.02s (244s) Rows=1.0 (15341), sakaiuser[sakaiuser]@6hosts
select count(N) from SAKAI_REALM_RL_FN MAINTABLE LEFT JOIN SAKAI_REALM_RL_GR GRANTED_ROLES ON (MAINTABLE.REALM_KEY = GRANTED_ROLES.REALM_KEY AND MAINTABLE.ROLE_KEY = GRANTED_ROLES.ROLE_KEY), SAKAI_REALM REALMS, SAKAI_REALM_ROLE ROLES, SAKAI_REALM_FUNCTION FUNCTIONS where (ROLES.ROLE_NAME in('S','S') or (GRANTED_ROLES.USER_ID = 'S' AND GRANTED_ROLES.ACTIVE = N)) AND FUNCTIONS.FUNCTION_NAME = 'S' AND REALMS.REALM_ID in ('S') AND MAINTABLE.REALM_KEY = REALMS.REALM_KEY AND MAINTABLE.FUNCTION_KEY = FUNCTIONS.FUNCTION_KEY AND MAINTABLE.ROLE_KEY = ROLES.ROLE_KEY
with an actual example (note the very large Rows_examined value).
Time: 120810 6:00:04
User@Host: sakaiuser[sakaiuser] @ srvslscle007.uct.ac.za [137.158.155.54]
Query_time: 1.238584 Lock_time: 0.000079 Rows_sent: 1 Rows_examined: 108164
SET timestamp=1344571204;
select count(1) from SAKAI_REALM_RL_FN MAINTABLE LEFT JOIN SAKAI_REALM_RL_GR GRANTED_ROLES ON (MAINTABLE.REALM_KEY = GRANTED_ROLES.REALM_KEY AND MAINTABLE.ROLE_KEY = GRANTED_ROLES.ROLE_KEY), SAKAI_REALM REALMS, SAKAI_REALM_ROLE ROLES, SAKAI_REALM_FUNCTION FUNCTIONS where (ROLES.ROLE_NAME in('.anon','.auth') or (GRANTED_ROLES.USER_ID = '0a8199d4-217f-4536-9c73-00d5257b9310' AND GRANTED_ROLES.ACTIVE = 1)) AND FUNCTIONS.FUNCTION_NAME = 'annc.all.groups' AND REALMS.REALM_ID in ('/site/375b9f7b-edb2-4c2f-bc70-09bf0adec334') AND MAINTABLE.REALM_KEY = REALMS.REALM_KEY AND MAINTABLE.FUNCTION_KEY = FUNCTIONS.FUNCTION_KEY AND MAINTABLE.ROLE_KEY = ROLES.ROLE_KEY;
Since adding the 'force index', realm queries no longer show up in our slow query log. However, it's hard to demonstrate slow performance under controlled conditions (except perhaps a realistic and intensive load test). Running EXPLAIN for some of the queries (without the force index changes) now shows different results on our db than was observed under load, so the query optimizer may be choosing different strategies under different conditions, some of which are sub-optimal. We experienced severe load issues from these queries on 3 or 4 different occasions, somewhat unpredictably.
One of our mysql 5.5 dev boxes appears to show different results for the choice of keys in EXPLAIN (i.e. chooses correct keys without use of force index), though hard to say whether that's a mysql version issue or because the tables there are unfragmented (as they're typically restored from a mysql dump).
So I'd still conclude that unless the 'force index' change shows adverse effects on smaller databases, the change is a precautionary measure which may benefit some production sites on some versions of mysql under significant load.
Permission checks like the one below turn out to be slow in sites with large membership. For example in one site with 22300 members, this query appears to scan 67544 rows, even though a mysql 'explain' would seem to suggest that the query is using indexes correctly and is relatively efficient.
A large number of such permission checks in a short space of time have in the past caused major performance problems for the database.
Query_time: 2 Lock_time: 0 Rows_sent: 1 Rows_examined: 67544
select count(1) from SAKAI_REALM_RL_FN MAINTABLE LEFT JOIN SAKAI_REALM_RL_GR GRANTED_ROLES ON (MAINTABLE.REALM_KEY =
GRANTED_ROLES.REALM_KEY AND MAINTABLE.ROLE_KEY = GRANTED_ROLES.ROLE_KEY), SAKAI_REALM REALMS, SAKAI_REALM_ROLE ROLES, SAKAI_REALM_FUNCTION FUNCTIONS where ( ROLES.ROLE_NAME in('.anon','.auth') or ( GRANTED_ROLES.USER_ID = 'xyz' AND GRANTED_ROLES.ACTIVE = 1 ) ) AND FUNCTIONS.FUNCTION_NAME = 'calendar.all.groups' AND REALMS.REALM_ID in ('/site/96dbcba6-01c2-4059-007a-40e484873bb9') AND MAINTABLE.REALM_KEY
= REALMS.REALM_KEY AND MAINTABLE.FUNCTION_KEY = FUNCTIONS.FUNCTION_KEY AND MAINTABLE.ROLE_KEY = ROLES.ROLE_KEY;