Performance issues on large forum (+500.000 posts)

Dear friends,

We are a charity migrating a large board from PhpBB to Drupal.

I would like to discuss performance issues on a large forum migrated from PhpBB. I have several modules installed. The database is PostgreSQL running on a quad-core computer with 16Gb RAM. All queries and running on memory, and I log any query > 30 ms. Here is an example:

2009-03-13 15:03:44 CET LOG:  durée : 53.637 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 31 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 54.958 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 50 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 53.917 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 4 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 54.516 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 28 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 34.181 ms, instruction : SELECT COUNT(cid) FROM comments WHERE nid = 43224
2009-03-13 15:03:44 CET LOG:  durée : 55.442 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 29 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 38.530 ms, instruction : SELECT COUNT(cid) FROM comments WHERE nid = 62786
2009-03-13 15:03:44 CET LOG:  durée : 55.774 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 26 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 54.591 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 25 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 55.845 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 27 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 54.963 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 23 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 33.059 ms, instruction : SELECT COUNT(cid) FROM comments WHERE nid = 66706
2009-03-13 15:03:44 CET LOG:  durée : 54.235 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 24 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 53.589 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 5 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 54.710 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 19 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:44 CET LOG:  durée : 53.537 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 22 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:45 CET LOG:  durée : 55.627 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 21 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:45 CET LOG:  durée : 55.590 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 18 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:45 CET LOG:  durée : 53.948 ms, instruction : SELECT COUNT(n.nid) FROM (SELECT DISTINCT ON (nid) * FROM node) n INNER JOIN term_node tn ON n.vid = tn.vid AND tn.tid = 20 LEFT JOIN history h ON n.nid = h.nid AND h.uid = 1 WHERE n.status = 1 AND n.created > 1234361013 AND h.nid IS NULL
2009-03-13 15:03:45 CET LOG:  durée : 117.758 ms, instruction : SELECT COUNT(DISTINCT(nid)) FROM forum
2009-03-13 15:03:47 CET LOG:  durée : 599.783 ms, instruction : SELECT COUNT(p1.post_id) AS prev_posts

My first question is: do you know where this query comes from and why it is running 20 times on each page connect?

The query plan is:

"Aggregate  (cost=4418.38..4418.39 rows=1 width=4) (actual time=80.487..80.487 rows=1 loops=1)"
"  ->  Nested Loop  (cost=12.98..4418.37 rows=1 width=4) (actual time=77.632..80.472 rows=6 loops=1)"
"        ->  Merge Left Join  (cost=12.98..4033.42 rows=56 width=8) (actual time=76.074..77.689 rows=1023 loops=1)"
"              Merge Cond: (n.nid = h.nid)"
"              Filter: (h.nid IS NULL)"
"              ->  Subquery Scan n  (cost=0.00..4020.11 rows=113 width=8) (actual time=75.962..77.210 rows=1029 loops=1)"
"                    Filter: ((n.created > 1234361013) AND (n.status = 1))"
"                    ->  Unique  (cost=0.00..3006.18 rows=67595 width=96) (actual time=0.041..62.621 rows=67484 loops=1)"
"                          ->  Index Scan using node_pkey on node  (cost=0.00..2837.19 rows=67595 width=96) (actual time=0.041..42.412 rows=67484 loops=1)"
"              ->  Sort  (cost=12.98..13.00 rows=10 width=4) (actual time=0.106..0.107 rows=11 loops=1)"
"                    Sort Key: h.nid"
"                    Sort Method:  quicksort  Memory: 25kB"
"                    ->  Bitmap Heap Scan on history h  (cost=4.33..12.81 rows=10 width=4) (actual time=0.061..0.073 rows=11 loops=1)"
"                          Recheck Cond: (uid = 1)"
"                          ->  Bitmap Index Scan on history_pkey  (cost=0.00..4.33 rows=10 width=0) (actual time=0.049..0.049 rows=11 loops=1)"
"                                Index Cond: (uid = 1)"
"        ->  Index Scan using term_node_vid_idx on term_node tn  (cost=0.00..6.86 rows=1 width=4) (actual time=0.002..0.002 rows=0 loops=1023)"
"              Index Cond: ((tn.vid)::integer = (n.vid)::integer)"
"              Filter: ((tn.tid)::integer = 18)"
"Total runtime: 80.637 ms"

Actualy, we have more than 500 users simultaneously connected. We cannot migrate until this kind of "mad" queries get fixed. Any idea how I could fix this query, so that it runs once.

Drupal framework is very nice, but I wonder if developers have access to SQL logs. MySQL is so simple and aging, that you don't realize what is being done. I hope I can help privide logs running under PostgreSQL, to help debugging. I can only encourage you to use PostgreSQL by the way.

Kind regards,
Jean-Michel