Redmine

Since updating to 0.9 Redmine has been showing up in my mySQL slow log every day. This is todays entry:

Count: 447  Time=0.94s (422s)  Lock=0.00s (0s)  Rows=2270.3 (1014805), redmine[redmine]@[192.168.0.2]
 SELECT `journals`.`id` AS t0_r0, `journals`.`journalized_id` AS t0_r1, `journals`.`journalized_type` AS t0_r2, `journals`.`user_id` AS t0_r3, `journals`.`notes` AS t0_r4, `journals`.`created_on` AS t0_r5, `issues`.`id` AS t1_r0, `issues`.`tracker_id` AS t1_r1, `issues`.`project_id` AS t1_r2, `issues`.`subject` AS t1_r3, `issues`.`description` AS t1_r4, `issues`.`due_date` AS t1_r5, `issues`.`category_id` AS t1_r6, `issues`.`status_id` AS t1_r7, `issues`.`assigned_to_id` AS t1_r8, `issues`.`priority_id` AS t1_r9, `issues`.`fixed_version_id` AS t1_r10, `issues`.`author_id` AS t1_r11, `issues`.`lock_version` AS t1_r12, `issues`.`created_on` AS t1_r13, `issues`.`updated_on` AS t1_r14, `issues`.`start_date` AS t1_r15, `issues`.`done_ratio` AS t1_r16, `issues`.`estimated_hours` AS t1_r17, `projects`.`id` AS t2_r0, `projects`.`name` AS t2_r1, `projects`.`description` AS t2_r2, `projects`.`homepage` AS t2_r3, `projects`.`is_public` AS t2_r4, `projects`.`parent_id` AS t2_r5, `projects`.`created_on` AS t2_r6, `projects`.`updated_on` AS t2_r7, `projects`.`identifier` AS t2_r8, `projects`.`status` AS t2_r9, `projects`.`lft` AS t2_r10, `projects`.`rgt` AS t2_r11, `journal_details`.`id` AS t3_r0, `journal_details`.`journal_id` AS t3_r1, `journal_details`.`property` AS t3_r2, `journal_details`.`prop_key` AS t3_r3, `journal_details`.`old_value` AS t3_r4, `journal_details`.`value` AS t3_r5, `users`.`id` AS t4_r0, `users`.`login` AS t4_r1, `users`.`hashed_password` AS t4_r2, `users`.`firstname` AS t4_r3, `users`.`lastname` AS t4_r4, `users`.`mail` AS t4_r5, `users`.`mail_notification` AS t4_r6, `users`.`admin` AS t4_r7, `users`.`status` AS t4_r8, `users`.`last_login_on` AS t4_r9, `users`.`language` AS t4_r10, `users`.`auth_source_id` AS t4_r11, `users`.`created_on` AS t4_r12, `users`.`updated_on` AS t4_r13, `users`.`type` AS t4_r14 FROM `journals`  LEFT OUTER JOIN `issues` ON `issues`.id = `journals`.journalized_id  LEFT OUTER JOIN `projects` ON `projects`.id!= `issues`.project_id  LEFT OUTER JOIN `journal_details` ON journal_details.journal_id = journals.id  LEFT OUTER JOIN `users` ON `users`.id = `journals`.user_id     WHERE (journals.journalized_type = 'Issue' AND (journal_details.prop_key = 'status_id' OR journals.notes <> '')) AND (1=1 AND (journals.created_on BETWEEN '2010-01-04' AND '2010-02-03') AND (((projects.status=1 AND EXISTS (SELECT em.id FROM enabled_modules em WHERE em.name='issue_tracking' AND em.project_id=projects.id)) AND (1=0 OR projects.is_public = 1 OR projects.id IN (10,9,12,1,4,5,8,2,3)))));

Which is being run 447 times a day at about a second each.

Explain gives this:

+----+--------------------+-----------------+--------+---------------------------------------------------------------------------------------+------------------------------+---------+---------------------------------+------+-------------+
| id | select_type        | table           | type   | possible_keys                                                                         | key                          | key_len | ref                             | rows | Extra       |
+----+--------------------+-----------------+--------+---------------------------------------------------------------------------------------+------------------------------+---------+---------------------------------+------+-------------+
|  1 | PRIMARY            | projects        | ALL    | PRIMARY                                                                               | NULL                         | NULL    | NULL                            |   29 | Using where | 
|  1 | PRIMARY            | journals        | range  | journals_journalized_id,index_journals_on_journalized_id,index_journals_on_created_on | index_journals_on_created_on | 8       | NULL                            | 1095 | Using where | 
|  1 | PRIMARY            | issues          | eq_ref | PRIMARY                                                                               | PRIMARY                      | 4       | redmine.journals.journalized_id |    1 | Using where | 
|  1 | PRIMARY            | journal_details | ref    | journal_details_journal_id                                                            | journal_details_journal_id   | 4       | redmine.journals.id             |    1 | Using where | 
|  1 | PRIMARY            | users           | eq_ref | PRIMARY,index_users_on_id_and_type                                                    | PRIMARY                      | 4       | redmine.journals.user_id        |    1 |             | 
|  2 | DEPENDENT SUBQUERY | em              | ref    | enabled_modules_project_id                                                            | enabled_modules_project_id   | 5       | redmine.projects.id             |    3 | Using where | 
+----+--------------------+-----------------+--------+---------------------------------------------------------------------------------------+------------------------------+---------+---------------------------------+------+-------------+
6 rows in set (0.01 sec)

Apparently all tables except projects are using an index, and all but journals are only inspecting a small number of rows, so explain looks OK (except the large number of joins) - no filesorts ect.

Still Redmine never used to appear in my slow query log so I flag this now.