Recently, a client approached 2bits.com for a consulting on performance.

Introduction: a popular site is a victim to its success

The site had 13,000+ nodes, with almost 12,000 of them being forum posts.

+------------+-------+
| type       | cnt   |
+------------+-------+
| forum      | 11994 |
| image      |   351 |
| weblink    |   269 |
| feed_item  |   153 |
| story      |   105 |
| resume     |    77 |
| poll       |    47 |
| blog       |    36 |
| page       |    26 |
| faq        |    24 |
| job        |    23 |
| chatroom   |     3 |
| simplenews |     2 |
| feed       |     1 |
+------------+-------+ 

The site uses the job search module with the resume access and job access modules to keep things private. Moreover, they have the taxonomy access control module to restrict some premium content to permium members.

+--------------+-------+
| realm        | cnt   |
+--------------+-------+
| term_access  | 32209 |
| resume_view  |    51 |
| resume_owner |    51 |
| job_view     |    19 |
+--------------+-------+

As you can see, the number of rows related to resumes and jobs is not the issue, but the number of rows from taxonomy access is where the bulk of the data is.

The main complaint was about the forum's main page. It took more than 11 seconds to generate the page for about 20 forums.

Executed 283 queries in 11515.54 milliseconds. Page execution time was 11662.6 ms. 

Diagnosis: identifying the problem

First monitoring the server, then using the devel module, we were able toidentify the problem. The heavy queries were as follows, each preceded with the number of milliseconds it took to generate each query:

683.98 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 26 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

683.96 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 28 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

673.34 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 5 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

673.15 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 27 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

672.71 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 6 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

671.58 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 7 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

671.41 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 34 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

671.31 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 8 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

671 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 4 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

670.71 1 forum_get_forums SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid INNER JOIN node_access na ON na.nid = n.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'job_view') OR (na.gid = 11284 AND na.realm = 'resume_owner') OR (na.gid = 2 AND na.realm = 'term_access'))) AND ( n.status = 1 AND n.type='forum' AND tn.tid = 3 ) ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

The problem here is that for each of the above queries, the node_access table was being joined, and since it has 32,000 rows, together with the other tables in the query, this caused a temporary table and a filesort operation to be performance, which is very slow.

Since the forums are the most active part of the site, this was of course slowing down the entire site and having a bad user experience.

Solution: Bybass the node_access table

The solution to this problem was a bit unconventional. Since all the forums are public, joining the node_access table would not add any value for forum posts. So, the core forum module was rewritten to bypass the node_access joins entirely, while keeping the new module compatible with the database tables and settings of the core forum module.

This showed immediate improvement: From 11,000 ms, we are down to 1300 only. 

Executed 235 queries in 1221.66 milliseconds. Page execution time was 1345.35 ms. 

The queries are much lighter on the server now:

389.93  1  xforum_get_forums  SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid WHERE n.status = 1 AND n.type='forum' AND tn.tid = 26 ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

50.44  1  xforum_get_forums  SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid WHERE n.status = 1 AND n.type='forum' AND tn.tid = 7 ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

44.59  1  xforum_get_forums  SELECT ncs.last_comment_timestamp, IF (ncs.last_comment_uid != 0, u2.name, ncs.last_comment_name) AS last_comment_name, ncs.last_comment_uid FROM node n INNER JOIN users u1 ON n.uid = u1.uid INNER JOIN term_node tn ON n.nid = tn.nid INNER JOIN node_comment_statistics ncs ON n.nid = ncs.nid INNER JOIN users u2 ON ncs.last_comment_uid=u2.uid WHERE n.status = 1 AND n.type='forum' AND tn.tid = 28 ORDER BY ncs.last_comment_timestamp DESC LIMIT 0, 1

So, no wonder you have node access as #8 on the community's wish list of improvements for Drupal 7. Not only do we need to make it easier to develop for, and use, but also we need it to be efficient.

Comments

I tried to create workable alternatives to node_access without destroying the system in D6, but I was stonewalled. In fact there was a belief that utilizing the node_access system even *more* was the direction to go, and I couldn't get anyone to seem to care that that particular join can cause very negative performance problems.

We'll have to see what happens in D7. This is a big deal to me.

Tue, 2008/02/26 - 21:33

Earl

You did a great job with Drupal 5 when node access modules can coexist together with less suckage than what used to be in 4.7.

As I said in the other comments, some modules over use node access. Perhaps that is one of the issues?

It is a tough one though. Can't think of an easy way to make the permissions granular enough yet not slow for performance.

I am looking forward to your node access changes for D7.
--
2bits -- Drupal and Backdrop CMS consulting

Pages

Is your Drupal or Backdrop CMS site slow?
Is it suffering from server resources shortages?
Is it experiencing outages?
Contact us for Drupal or Backdrop CMS Performance Optimization and Tuning Consulting