Hi Ralf:
I did a quick instrumentation of hasPermission in my custom tracker.
I displayed an issue index page logged in as admin with Admin role.
The index page has the following columns:
ID, Activity, Title, Status, Creator, Assigned To
and groups by Priority. Using:
grep hasPermission roundup.log| sed 's/^.*DEBUG: //' | sort | uniq -c | sort -n
I see 1241 calls of which 533 are not issue class calls. One in
particular stands out. Stats are:
(name, userid, class, property, itemid) (roles scanned, perms scanned):
426 hasPermission: (Web Access, 1, None, None, None) (1, 6) allow
So this check alone is 2556 permission evaulations. Just removing that
from the permissions list gets rid of 5*426 permission checks and 30%
of the calls to hasPermissions. Memoizing this would be a big win if
we can't eliminate/cache the 'Web Access' call at a higher level.
I have 15 sets of other non-issue calls that look like:
1 hasPermission: (View, 1, query, klass, 4) (1, 5) allow
1 hasPermission: (View, 1, query, url, 4) (1, 5) allow
3 hasPermission: (View, 1, query, name, 4) (1, 5) allow
which makes sense as they are queries showing up in my sidebar. (Not
quite sure about the origin for the klass property check). I also have
the following 12 times:
1 hasPermission: (View, 1, keyword, None, 10) (1, 5) allow
one for each keyword I own. Again not sure where that is triggered.
Then some randoms:
1 hasPermission: (Create, 1, user, None, None) (1, 1) allow
Create user link
2 hasPermission: (Create, 1, keyword, None, None) (1, 1) allow
display the create keyword link inefficiently (the second call should
be replaced by a predefined template variable 8-)).
1 hasPermission: (Edit, 1, None, None, None) (1, 2) allow
1 hasPermission: (Edit, 1, keyword, None, None) (1, 2) allow
display the edit existing keyword link (db.keyword.list is called as
well which is probably the trigger for the keyword prop check, if I
don't own any keywords I can't edit them)
1 hasPermission: (Register, 1, user, None, None) (1, 14) deny
display the register link if the user has permission.
1 hasPermission: (View, 1, user, username, 1) (1, 5) allow
to display my login name (hello admin)
2 hasPermission: (View, 1, user, None, None) (1, 5) allow
user admin links.
2 hasPermission: (View, 1, user, theme, 1) (1, 5) allow
loading a theme for the tracker.
Then we have:
4 hasPermission: (Create, 1, issue, None, None) (1, 1) allow
I am not sure about the origin. I only have two create issue
links in the template. Also:
4 hasPermission: (View, 1, issue, None, None) (1, 5) allow
not sure why there are 4.
Also this seems to indicate that View permissions are lower in the
permission list than create or edit. It seems they are satisfied on
the fifth permission check. But View also get used more often. So
there may be some additional optimization we can do there to reduce
the number of permissions checked to get an allow response.
Then for each issue (50 total) it looks like:
1 hasPermission: (View, 1, issue, activity, 210) (1, 5) allow
1 hasPermission: (View, 1, issue, assignedto, 210) (1, 5) allow
1 hasPermission: (View, 1, issue, creator, 210) (1, 5) allow
1 hasPermission: (View, 1, issue, priority, 210) (1, 5) allow
1 hasPermission: (View, 1, issue, title, 210) (1, 5) allow
(*) 2 hasPermission: (View, 1, issue, None, 210) (1, 5) allow
2 hasPermission: (View, 1, issue, status, 210) (1, 5) allow
The * log is present for every issue even those that are NOT
displayed. I only show 50 of the 173 displayed.
So this is another thing to look at. We fetch and check perms on a lot
more items for an issue index even if they aren't displayed. Since
none of these rows are displayed, only issue item checks without
property permission checks are done. I wonder if this is a major cause
of your slowdown?
Maybe we can stop checking permissions once we have page_size number
of rows?
We could also fetch fewer rows similar to the hack/patch discussed in
issue 2551328.But this patch uses the offset and page number to
calculate the database offset. If there are a lot of discarded
entries, the patch can refetch rows that were already shown in a prior
page. Also the count (issues 50 of 435) is not valid since the db
fetch may be smaller than the total number of permitted rows. I don't
have a good idea for addressing the potential miscount. |