CiviCRM Community Forums (archive)

Hello,

Site stats:

Drupal 7.23
CiviCRM 4.3
MySQL 5.5.36

This morning I had one of my clients websites go down, the following error was returned on all requests:

Error
The website encountered an unexpected error. Please try again later.
Error message
PDOException: SQLSTATE[42000] [1203] User client_____ already has more than 'max_user_connections' active connections in lock_may_be_available() (line 167 of /home/username/public_html/drupal/includes/lock.inc).

This happened after we attempted to use the CiviGroup Roles Sync module to sync some user registrations.  After investigating, we noticed that MySQL CPU and memory were spiking and as such MySQL was unresponsive.  Taking a look at SHOW PROCESSLIST at that time, showed that there were some queries on the CiviCRM database that were clearly to blame:

+----------+-------------+-----------+------------------------+---------+-------+---------------------------------+------------------------------------------------------------------------------------------------------+
| Id       | User        | Host      | db                     | Command | Time  | State                           | Info                                                                                                 |
+----------+-------------+-----------+------------------------+---------+-------+---------------------------------+------------------------------------------------------------------------------------------------------+
| 14616996 | client_____ | localhost | client_civicrm_db_____ | Query   | 97025 | Copying to tmp table            | SELECT count(DISTINCT contact_a.id) as rowCount  FROM civicrm_contact contact_a  LEFT JOIN civicrm_g |
| 15176334 | client_____ | localhost | client_civicrm_db_____ | Query   | 93205 | Copying to tmp table            | SELECT DISTINCT UPPER(LEFT(contact_a.sort_name, 1)) as sort_name  FROM civicrm_contact contact_a  LE |
| 15196152 | client_____ | localhost | client_civicrm_db_____ | Query   | 91584 | Copying to tmp table            | SELECT DISTINCT UPPER(LEFT(contact_a.sort_name, 1)) as sort_name  FROM civicrm_contact contact_a  LE |
| 15213642 | client_____ | localhost | client_civicrm_db_____ | Query   | 90371 | Copying to tmp table            | SELECT DISTINCT UPPER(LEFT(contact_a.sort_name, 1)) as sort_name  FROM civicrm_contact contact_a  LE |
| 15221325 | client_____ | localhost | client_civicrm_db_____ | Query   | 89716 | Copying to tmp table            | SELECT DISTINCT UPPER(LEFT(contact_a.sort_name, 1)) as sort_name  FROM civicrm_contact contact_a LEF |
| 15221947 | client_____ | localhost | client_civicrm_db_____ | Query   | 89658 | Copying to tmp table            | SELECT DISTINCT UPPER(LEFT(contact_a.sort_name, 1)) as sort_name  FROM civicrm_contact contact_a LEF |
| 15822898 | client_____ | localhost | client_civicrm_db_____ | Query   |  8276 | Waiting for table metadata lock | DROP TRIGGER IF EXISTS civicrm_contact_before_insert                                                 |
| 15824757 | client_____ | localhost | client_civicrm_db_____ | Query   |  8100 | Waiting for table metadata lock | SELECT  IF ( SUM( value.count*lineItem.qty ),
                 SUM( value.count*lineItem.qty ) +
    |
| 15827514 | client_____ | localhost | client_civicrm_db_____ | Query   |  7710 | Waiting for table metadata lock | SELECT    civicrm_contact.display_name as display_name,
          civicrm_contact.contact_type as co |
| 15827522 | client_____ | localhost | client_civicrm_db_____ | Query   |  7709 | Waiting for table metadata lock | SELECT    civicrm_contact.display_name as display_name,
          civicrm_contact.contact_type as co |
| 15831376 | client_____ | localhost | client_civicrm_db_____ | Query   |  7240 | Waiting for table metadata lock | SELECT    civicrm_contact.display_name as display_name,
          civicrm_contact.contact_type as co |
| 15832671 | client_____ | localhost | client_civicrm_db_____ | Query   |  7060 | Waiting for table metadata lock | SELECT    civicrm_contact.display_name as display_name,
          civicrm_contact.contact_type as co |
| 15833862 | client_____ | localhost | client_civicrm_db_____ | Query   |  6892 | Waiting for table metadata lock | SELECT contact_a.id as contact_id, contact_a.contact_type  as `contact_type`, contact_a.contact_sub_ |
| 15836057 | client_____ | localhost | client_civicrm_db_____ | Query   |  6578 | Waiting for table metadata lock | INSERT INTO dedupe (id1, weight)
                SELECT contact.id as id1, 10 as weight
            |
| 15837723 | client_____ | localhost | client_civicrm_db_____ | Query   |  6347 | Waiting for table metadata lock | SELECT  count(*)
  FROM  civicrm_contact
 WHERE  id IN (10545, 5274 )                                |
| 15840486 | client_____ | localhost | client_civicrm_db_____ | Query   |  5992 | Waiting for table metadata lock | SELECT  count(*)
  FROM  civicrm_contact
 WHERE  id IN (10545, 47383 )                               |
| 15841292 | client_____ | localhost | client_civicrm_db_____ | Query   |  5905 | Waiting for table metadata lock | SELECT *
 FROM civicrm_contact
 
 WHERE (  civicrm_contact.id = 14750 )                            |
| 15842863 | client_____ | localhost | client_civicrm_db_____ | Query   |  5726 | Waiting for table metadata lock | SELECT DISTINCT(civicrm_mailing_event_queue.contact_id) as contact_id,
       civicrm_contact.displa |
| 15843492 | client_____ | localhost | client_civicrm_db_____ | Query   |  5637 | Waitinquitg for table metadata lock | SELECT *
 FROM civicrm_contact
 
 WHERE (  civicrm_contact.id = 129 )                              |
| 15844541 | client_____ | localhost | client_civicrm_db_____ | Query   |  5524 | Waiting for table metadata lock | SELECT  count(*)
  FROM  civicrm_contact
 WHERE  id IN (10545, 5274 )                                |
| 15845363 | client_____ | localhost | client_civicrm_db_____ | Query   |  5424 | Waiting for table metadata lock | INSERT INTO dedupe (id1, weight)
                SELECT contact.id as id1, 10 as weight
            |
| 15846134 | client_____ | localhost | client_civicrm_db_____ | Query   |  5331 | Waiting for table metadata lock | SELECT *
 FROM civicrm_contact
 
 WHERE (  civicrm_contact.id = 129 )                              |
| 15846491 | client_____ | localhost | client_civicrm_db_____ | Query   |  5283 | Waiting for table metadata lock | SELECT *
 FROM civicrm_contact
 
 WHERE (  civicrm_contact.id = 129 )                              |
| 15846708 | client_____ | localhost | client_civicrm_db_____ | Query   |  5251 | Waiting for table metadata lock | SELECT  is_deleted 
 FROM civicrm_contact
 
 WHERE (  civicrm_contact.id = 129 )                   |
| 15893757 | client_____ | localhost | client_civicrm_db_____      | Query   |     0 | NULL                            | show processlist                                                                                     |
+----------+-------------+-----------+------------------------+---------+-------+---------------------------------+------------------------------------------------------------------------------------------------------+
25 rows in set (0.00 sec)

To resolve the immediate issue, I ran the MySQL KILL <process_id> command to stop the top 6 SELECT queries in the 'Copying to tmp table' state that had been running for more than a day.  After that the remaining queries completed and the site became responsive again.

We believe those top 6 queries stem from a Contact search in which we we're trying to search contacts by Group and Created date range after Oct of last year.  The client had been having trouble with such queries and we were investigating.  In that case, the site would become unresponsive (spinning on the search request) and eventually coming back with a 404 response.

Has anyone seen this behaviour before?  Does anyone recognize the queries that were blocking everything?  What can we do to fix this long term?  Are there performance related updates > CiviCRM 4.3 that could help?

Any advice is appreciated.

Thanks,
Matthew Oliveira

would be great if your org can contribute resources / $$$ or a patch to help fix and improve the below query (which is part of the search sub-system)

In the below case specifically where we dont need the name of who modified the contact, the left join is not needed

We've also started storing the modified and created dates in the contact table, so it can be made even more efficient.

i suspect its a 10-20 hour project to make these improvements

lobo

1. there is an option in search preferences to disable the A-Z pager (which speeds things up a fair bit)

2. The search code is in CRM/Contact/BAO/Query.php. the changeLog function should have most of the changeLog specific part of the code

3. I think if we add created_id / modified_id to the civicrm_contact table, we can bypass the civicrm_log table completely for all searches. But for a search by date range, we dont need the left join to the contact table anyway

lobo

So I took a look at what's evolved between 4.3.5 and 4.4.4 in the functions I noted.  Turns out little has changed, except somewhere between the two versions, the subquery with the expensive GROUP BY is removed.  Tried that on the 4.3.5 copy my client is on and it got the query performant enough that the page now responds normally and returns the result instead of hanging MySQL.

Thus while it works now, could still be made better.  I'll see if I can get resources to work on this.  Will keep posted.

In the end, I'll likely patch 4.3.5 and schedule an upgrade for the client in the near future.  I'll post the patch that works for me when available.

Thanks,
Matt