CiviCase particularly slow

[nickholden]

Hi all,

Our CiviCRM deployment has a few thousand contacts in it, each one with an average of one civicase entry. Users report that the process of viewing a contact's cases involves a delay of some seconds while the database search is performed. The other functions of the site seem fine and there's no obvious problem with configuration. When accessing the 'Cases' tab of a contact's record, the little 'wait' icon displays for a few seconds and the CPU use on the MySQL server reaches up to 100% before the results are returned and the page is drawn. Is there an issue with CiviCase database calls needing to be optimized, or is something else going on? Do other people notice CiviCase as being the 'slow' component?

Thanks

Nick

[Donald Lobo]

R u on 4.2.0? If so might want to do a test upgrade to 4.3.x and see if the queries have been optimized in more recent versions

yes, it does seems like the case dashboard queries are a bit slow. Would be good if you can take a look at the queries generated (mysql query log?) and see how we can optimize it for better performance.

In general many of these bottleneck queries are fairly easy to optimize once we've tracked it down and have a reasonable dataset. Typucally a 3-10 hour project

lobo

[nickholden]

Thanks Lobo. Yeah, we're on 4.2.4 and I will get around to an upgrade in the next few days, at least on our test system.

The culprit seems to be this query.... this is from a mysqlsla reading of a log for the past few days. It's the number one slow query in my logs. I've also verified that it is the query being run at the point that the UI hangs up waiting for the CiviCase list to be populated.

An average of 123 million rows examined in order to send one result set!

Count         : 33  (39.29%)
Time          : 965.165314 s total, 29.247434 s avg, 23.684252 s to 53.445952 s max  (69.10%)
  95% of Time : 861.690871 s total, 27.79648 s avg, 23.684252 s to 47.892503 s max
Lock Time (s) : 45.158 ms total, 1.368 ms avg, 789 µs to 2.107 ms max  (24.45%)
  95% of Lock : 41.312 ms total, 1.333 ms avg, 789 µs to 1.729 ms max
Rows sent     : 1 avg, 0 to 1 max  (0.00%)
Rows examined : 123.40M avg, 122.71M to 124.20M max  (95.18%)
Database      : HIDDEN
Users         :
   HIDDEN@HIDDEN : 100.00% (33) of query, 39.29% (33) of all users

Query abstract:
SET timestamp=N; SELECT civicrm_case.id AS case_id, civicrm_case.subject AS case_subject, civicrm_contact.id AS contact_id, civicrm_contact.sort_name AS sort_name, civicrm_phone.phone AS phone, civicrm_contact.contact_type AS contact_type, civicrm_contact.contact_sub_type AS contact_sub_type, t_act.activity_type_id, cov_type.label AS case_type, cov_type.name AS case_type_name, cov_status.label AS case_status, cov_status.label AS case_status_name, t_act.status_id, civicrm_case.start_date AS case_start_date, case_relation_type.label_b_a AS case_role, t_act.desired_date AS case_scheduled_activity_date, t_act.id AS case_scheduled_activity_id, t_act.act_type_name AS case_scheduled_activity_type_name, t_act.act_type AS case_scheduled_activity_type FROM civicrm_case INNER JOIN civicrm_case_contact ON civicrm_case.id = civicrm_case_contact.case_id INNER JOIN civicrm_contact ON civicrm_case_contact.contact_id = civicrm_contact.id INNER JOIN ( SELECT act3.case_id, act3.minid AS id, act_details.activity_date_time AS desired_date, act_details.activity_type_id, act_details.status_id, aov.name AS act_type_name, aov.label AS act_type FROM civicrm_view_case_activity_upcoming act_details INNER JOIN ( SELECT t.case_id, MIN(act2.id) AS minid FROM civicrm_view_case_activity_upcoming act2 INNER JOIN (SELECT vu.case_id, MIN(vu.activity_date_time) AS mindate FROM civicrm_view_case_activity_upcoming vu GROUP BY vu.case_id ORDER BY NULL ) AS t ON act2.activity_date_time = t.mindate GROUP BY t.case_id ORDER BY NULL ) AS act3 ON act3.minid = act_details.id LEFT JOIN civicrm_option_group aog ON aog.name='S' LEFT JOIN civicrm_option_value aov ON (aov.option_group_id = aog.id AND aov.value = act_details.activity_type_id) ) AS t_act ON t_act.case_id = civicrm_case.id LEFT JOIN civicrm_phone ON (civicrm_phone.contact_id = civicrm_contact.id AND civicrm_phone.is_primary=N) LEFT JOIN civicrm_relationship case_relationship ON ( case_relationship.contact_id_a = civicrm_case_contact.contact_id AND case_relationship.contact_id_b = N AND case_relationship.case_id = civicrm_case.id ) LEFT JOIN civicrm_relationship_type case_relation_type ON ( case_relation_type.id = case_relationship.relationship_type_id AND case_relation_type.id = case_relationship.relationship_type_id ) LEFT JOIN civicrm_option_group cog_type ON cog_type.name = 'S' LEFT JOIN civicrm_option_value cov_type ON ( civicrm_case.case_type_id = cov_type.value AND cog_type.id = cov_type.option_group_id ) LEFT JOIN civicrm_option_group cog_status ON cog_status.name = 'S' LEFT JOIN civicrm_option_value cov_status ON ( civicrm_case.status_id = cov_status.value AND cog_status.id = cov_status.option_group_id ) WHERE (N) AND civicrm_case_contact.contact_id IN( N ) AND civicrm_case.id IN( N) AND civicrm_case.is_deleted = N ORDER BY case_scheduled_activity_date ASC;

Query sample:
SET timestamp=1379667289;
SELECT
civicrm_case.id as case_id,
civicrm_case.subject as case_subject,
civicrm_contact.id as contact_id,
civicrm_contact.sort_name as sort_name,
civicrm_phone.phone as phone,
civicrm_contact.contact_type as contact_type,
civicrm_contact.contact_sub_type as contact_sub_type,
t_act.activity_type_id,
cov_type.label as case_type,
cov_type.name as case_type_name,
cov_status.label as case_status,
cov_status.label as case_status_name,
t_act.status_id,
civicrm_case.start_date as case_start_date,
case_relation_type.label_b_a as case_role,
t_act.desired_date as case_scheduled_activity_date,
t_act.id as case_scheduled_activity_id,
t_act.act_type_name as case_scheduled_activity_type_name,
t_act.act_type AS case_scheduled_activity_type  FROM civicrm_case
                  INNER JOIN civicrm_case_contact ON civicrm_case.id = civicrm_case_contact.case_id
                  INNER JOIN civicrm_contact ON civicrm_case_contact.contact_id = civicrm_contact.id  INNER JOIN
(
SELECT act3.case_id, act3.minid AS id, act_details.activity_date_time AS desired_date, act_details.activity_type_id,
act_details.status_id, aov.name AS act_type_name, aov.label AS act_type
FROM civicrm_view_case_activity_upcoming act_details INNER JOIN
(
  SELECT t.case_id, MIN(act2.id) as minid FROM civicrm_view_case_activity_upcoming act2 INNER JOIN
    (SELECT vu.case_id, MIN(vu.activity_date_time) AS mindate FROM civicrm_view_case_activity_upcoming vu
     GROUP BY vu.case_id ORDER BY NULL
    ) AS t
  ON act2.activity_date_time = t.mindate
  GROUP BY t.case_id ORDER BY NULL
) AS act3
ON act3.minid = act_details.id
LEFT JOIN civicrm_option_group aog ON aog.name='activity_type'
LEFT JOIN civicrm_option_value aov ON (aov.option_group_id = aog.id AND aov.value = act_details.activity_type_id)
) AS t_act
        ON t_act.case_id = civicrm_case.id
LEFT JOIN civicrm_phone ON (civicrm_phone.contact_id = civicrm_contact.id AND civicrm_phone.is_primary=1)
LEFT JOIN civicrm_relationship case_relationship
 ON ( case_relationship.contact_id_a = civicrm_case_contact.contact_id AND case_relationship.contact_id_b = 173
      AND case_relationship.case_id = civicrm_case.id )
LEFT JOIN civicrm_relationship_type case_relation_type
 ON ( case_relation_type.id = case_relationship.relationship_type_id
      AND case_relation_type.id = case_relationship.relationship_type_id )
LEFT JOIN civicrm_option_group cog_type
 ON cog_type.name = 'case_type'
LEFT JOIN civicrm_option_value cov_type
 ON ( civicrm_case.case_type_id = cov_type.value
      AND cog_type.id = cov_type.option_group_id )
LEFT JOIN civicrm_option_group cog_status
 ON cog_status.name = 'case_status'
LEFT JOIN civicrm_option_value cov_status
 ON ( civicrm_case.status_id = cov_status.value
      AND cog_status.id = cov_status.option_group_id )
 WHERE (1)
AND civicrm_case_contact.contact_id IN( 7535 )
AND civicrm_case.id IN( 7244)
AND civicrm_case.is_deleted     = 0  ORDER BY case_scheduled_activity_date ASC;

[nickholden]

So, I've run an explain on the query.

The result set is:

Code: [Select]


+----+-------------+----------------------+--------+-----------------------------------------------------------------------------------------------------------+--------------------------------------+---------+--------------------------------------------------------+-------+---------------------------------+
| id | select_type | table                | type   | possible_keys                                                                                             | key                                  | key_len | ref                                                    | rows  | Extra                           |
+----+-------------+----------------------+--------+-----------------------------------------------------------------------------------------------------------+--------------------------------------+---------+--------------------------------------------------------+-------+---------------------------------+
|  1 | PRIMARY     | civicrm_case         | const  | PRIMARY,index_is_deleted                                                                                  | PRIMARY                              | 4       | const                                                  |     1 | Using temporary; Using filesort |
|  1 | PRIMARY     | civicrm_contact      | const  | PRIMARY                                                                                                   | PRIMARY                              | 4       | const                                                  |     1 |                                 |
|  1 | PRIMARY     | civicrm_case_contact | ref    | UI_case_contact_id,FK_civicrm_case_contact_contact_id                                                     | UI_case_contact_id                   | 8       | const,const                                            |     1 | Using index                     |
|  1 | PRIMARY     | civicrm_phone        | ref    | index_is_primary,FK_civicrm_phone_contact_id                                                              | FK_civicrm_phone_contact_id          | 5       | const                                                  |     1 |                                 |
|  1 | PRIMARY     | case_relationship    | ref    | FK_civicrm_relationship_contact_id_a,FK_civicrm_relationship_contact_id_b,FK_civicrm_relationship_case_id | FK_civicrm_relationship_case_id      | 5       | const                                                  |     1 |                                 |
|  1 | PRIMARY     | case_relation_type   | eq_ref | PRIMARY                                                                                                   | PRIMARY                              | 4       | genvasc_civicrm.case_relationship.relationship_type_id |     1 |                                 |
|  1 | PRIMARY     | <derived2>           | ALL    | NULL                                                                                                      | NULL                                 | NULL    | NULL                                                   |  3149 | Using where; Using join buffer  |
|  1 | PRIMARY     | cog_type             | const  | UI_name                                                                                                   | UI_name                              | 194     | const                                                  |     1 | Using index                     |
|  1 | PRIMARY     | cov_type             | ref    | index_option_group_id_value,index_option_group_id_name                                                    | index_option_group_id_value          | 771     | const,genvasc_civicrm.cog_type.id                      |     1 |                                 |
|  1 | PRIMARY     | cog_status           | const  | UI_name                                                                                                   | UI_name                              | 194     | const                                                  |     1 | Using index                     |
|  1 | PRIMARY     | cov_status           | ref    | index_option_group_id_value,index_option_group_id_name                                                    | index_option_group_id_name           | 4       | genvasc_civicrm.cog_status.id                          |     3 |                                 |
|  2 | DERIVED     | <derived3>           | ALL    | NULL                                                                                                      | NULL                                 | NULL    | NULL                                                   |  3149 |                                 |
|  2 | DERIVED     | a                    | eq_ref | PRIMARY,index_is_current_revision,index_is_deleted                                                        | PRIMARY                              | 4       | act3.minid                                             |     1 | Using where                     |
|  2 | DERIVED     | ca                   | ref    | FK_civicrm_case_activity_activity_id                                                                      | FK_civicrm_case_activity_activity_id | 4       | genvasc_civicrm.a.id                                   |     1 | Using index                     |
|  2 | DERIVED     | aog                  | const  | UI_name                                                                                                   | UI_name                              | 194     |                                                        |     1 | Using index                     |
|  2 | DERIVED     | aov                  | ref    | index_option_group_id_value,index_option_group_id_name                                                    | index_option_group_id_name           | 4       | genvasc_civicrm.aog.id                                 |     3 |                                 |
|  3 | DERIVED     | <derived4>           | ALL    | NULL                                                                                                      | NULL                                 | NULL    | NULL                                                   |  3149 | Using where; Using temporary    |
|  3 | DERIVED     | ca                   | index  | FK_civicrm_case_activity_activity_id                                                                      | FK_civicrm_case_activity_activity_id | 4       | NULL                                                   | 39940 | Using index; Using join buffer  |
|  3 | DERIVED     | a                    | eq_ref | PRIMARY,index_is_current_revision,index_is_deleted                                                        | PRIMARY                              | 4       | genvasc_civicrm.ca.activity_id                         |     1 | Using where                     |
|  4 | DERIVED     | a                    | ref    | PRIMARY,index_is_current_revision,index_is_deleted                                                        | index_is_current_revision            | 2       |                                                        | 15718 | Using where; Using temporary    |
|  4 | DERIVED     | ca                   | ref    | FK_civicrm_case_activity_activity_id                                                                      | FK_civicrm_case_activity_activity_id | 4       | genvasc_civicrm.a.id                                   |     1 |                                 |
+----+-------------+----------------------+--------+-----------------------------------------------------------------------------------------------------------+--------------------------------------+---------+--------------------------------------------------------+-------+---------------------------------+
21 rows in set (24.76 sec)

The query complexity is melting my brain, but if you can spot what optimisation I might try on the query I'll give it a go. One thing I'm struggling with up front is that some of the table aliases referenced here ("ca" and "a" in particular) don't seem to actually be specified as part of the query. What am I missing?

[Donald Lobo]

sorry, but that query is fairly complex for a quick analysis. In many cases we reuse the same query for different purposes and hence add a few un-necessary tables (and we should optimize that and let the caller pass in enough info etc)

In the recent past, we've started splitting queries and using temp tables quite successfully. They slow things a wee bit for smaller data sets, but speed things up like crazy for large data sets. So i'd probably approach it that way

lobo

[demeritcowboy]

There were some changes made in both 4.3 and I think also 4.4 so I'd check out the upgrade before spending too much time on it.

If you still want to take a run at this query though the "ca" is in the view definition (civicrm_view_case_activity_upcoming and civicrm_view_case_activity_recent).

[nickholden]

Yep, it's much better in 4.4 - doing nothing turned out to be the right thing to do!