Queries getting stuck on 'creating sort index', slowing Sugar down.

Hey! 

A client of ours is experiencing some weird slowness issue in Sugar 7.9 running on MySQL 5.7. 

The problem is caused by some of the sql queries taking an extremely long time which effectively causes many of them to get stacked. This in turn eats up the server resources causing everything to slow down. The query execution gets stuck in the creating sort index phase, see the attached screen shot.

MySQL process list

The MySQL instance is housed on a separate virtual server with 8 CPU cores assigned and 32GB of RAM.

The data itself with indexes is around 16,9GB. The CALLS module has only 55k rows.

It appears that the problem manifests itself only after some uptime of the MySQL instance. After restarting the database server things seem to be working fine for up to a few days. 

Below is the database server config. We tried a couple of config changes (increasing buffers, table cache, tmp table size) but in the end the problem always comes back after a while. 

[mysqld]
sql_mode=""
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
datadir = /var/lib/mysql
log-error = /var/log/mysql/error.log
symbolic-links=0
skip-name-resolve
max_connections=300
innodb_temp_data_file_path = ibtmp1:12M:autoextend:max:128G
innodb_buffer_pool_size = 17G
innodb_log_file_size = 2125M
join_buffer_size = 32M
sort_buffer_size = 5M
read_rnd_buffer_size = 1M
table_definition_cache = 20000
table_open_cache = 150000
innodb_open_files = 150000
innodb_buffer_pool_instances = 17
innodb_lru_scan_depth = 100
tmp_table_size=640M
max_heap_table_size=640M
optimizer_search_depth=0

EDIT: 
Below is one of the queries that gets stuck, I suspect it's a Sugar stock query for hydrating the Calls notifications a user gets in the UI periodically. 

SELECT calls.id,
       calls.date_modified,
       calls.assigned_user_id,
       calls.created_by,
       calls.name,
       calls.date_entered,
       calls.modified_user_id,
       jt1_modified_user_link.first_name rel_modified_by_name_first_name,
       jt1_modified_user_link.last_name rel_modified_by_name_last_name,
       jt1_modified_user_link.created_by modified_by_name_owner,
       jt2_created_by_link.first_name rel_created_by_name_first_name,
       jt2_created_by_link.last_name rel_created_by_name_last_name,
       jt2_created_by_link.created_by created_by_name_owner,
       calls.description,
       calls.deleted,
       calls.duration_hours,
       calls.duration_minutes,
       calls.date_start,
       calls.date_end,
       calls.parent_type,
       calls.status,
       calls.direction,
       calls.parent_id,
       calls.reminder_time,
       calls.email_reminder_time,
       calls.email_reminder_sent,
       calls.outlook_id,
       jt3_contacts.id contact_id,
       jt3_contacts.salutation rel_contact_name_salutation,
       jt3_contacts.first_name rel_contact_name_first_name,
       jt3_contacts.last_name rel_contact_name_last_name,
       jt3_contacts.assigned_user_id contact_name_owner,
       LTRIM(RTRIM(CONCAT(IFNULL(jt3_contacts.first_name,''),' ',IFNULL(jt3_contacts.last_name,'')))) contact_name,
       calls.repeat_type,
       calls.repeat_interval,
       calls.repeat_dow,
       calls.repeat_until,
       calls.repeat_count,
       calls.repeat_selector,
       calls.repeat_days,
       calls.repeat_ordinal,
       calls.repeat_unit,
       calls.repeat_parent_id,
       calls.recurrence_id,
       calls.recurring_source,
       CASE
           WHEN jt4_following_link.id IS NOT NULL THEN 1
           ELSE 0
       END following,
       CASE
           WHEN jt5_favorite_link.id IS NOT NULL THEN 1
           ELSE 0
       END my_favorite,
       jt6_tag_link.name tag,
       jt6_tag_link.assigned_user_id tag_owner,
       jt7_locked_fields_link.pro_locked_variables locked_fields,
       jt7_locked_fields_link.assigned_user_id locked_fields_owner,
       jt8_assigned_user_link.first_name rel_assigned_user_name_first_name,
       jt8_assigned_user_link.last_name rel_assigned_user_name_last_name,
       jt8_assigned_user_link.created_by assigned_user_name_owner,
       calls.team_id,
       calls.team_set_id,
       calls.acl_team_set_id,
       jt9_team_count_link.created_by team_count_owner,
       calls_cstm.is_callback_c,
       calls_cstm.gsv_package_c,
       calls_cstm.schedule_call_back_on_c,
       calls_cstm.out_of_business_c,
       calls_cstm.gsv_pitch_c,
       calls_cstm.optima_pitch_c,
       calls_cstm.text_sale_amount_c,
       calls_cstm.text_package_c,
       calls_cstm.print_pitch_c,
       calls_cstm.location_c,
       calls_cstm.gsv_sale_amount_c,
       calls_cstm.created_account_type_c,
       calls_cstm.print_sale_out_of_town_c,
       calls_cstm.optima_package_c,
       calls_cstm.hot_callback_c,
       calls_cstm.shared_a_story_c,
       calls_cstm.print_sale_in_town_c,
       calls_cstm.text_pitch_c,
       calls_cstm.optima_sale_amount_c,
       calls_cstm.hmra_sale_amount_c,
       calls_cstm.sold_amt_c,
       calls_cstm.asked_closing_question_c,
       calls_cstm.presentation_result_c,
       calls_cstm.past_due_collected_c,
       calls_cstm.hmra_package_c,
       calls_cstm.hmra_pitch_c,
       calls_cstm.pay_amt_c,
       calls_cstm.call_type_calc_text_c,
       calls_cstm.call_type_c,
       calls_cstm.hot_c,
       jt10_amp_pitchingassignments_accounts.id amp_pitchingassignments_accountsamp_pitchingassignments_ida,
       jt10_amp_pitchingassignments_accounts.assigned_user_id amp_pitchingassignments_accountsamp_pitchingassignments_ida_owner,
       jt10_amp_pitchingassignments_accounts.name amp_pitchingassignments_accounts_name,
       jt10_amp_pitchingassignments_accounts.assigned_user_id amp_pitchingassignments_accounts_name_owner,
       calls_cstm.call_status_calc_text_c,
       calls_cstm.pos_percentage_c,
       calls_cstm.referrals_new_c,
       calls_cstm.canvassassignmentstatus_c,
       calls_cstm.cross_off_c,
       jt10_amp_pitchingassignments_accounts.id id_account_done,
       jt10_amp_pitchingassignments_accounts.assigned_user_id id_account_done_owner,
       jt10_amp_pitchingassignments_accounts.name account_done,
       jt10_amp_pitchingassignments_accounts.assigned_user_id account_done_owner,
       calls_cstm.special_placement_c,
       calls_cstm.number_of_ads_sold_c,
       calls_cstm.newaccount_c,
       calls_cstm.homebasedbusiness_c,
       calls_cstm.sharedstory_c,
       calls_cstm.askedaclosingquestion_c,
       calls_cstm.base_rate,
       calls_cstm.currency_id,
       calls_cstm.is_role_c,
       calls_cstm.print_sale_amount_c
FROM calls
INNER JOIN
  (SELECT tst.team_set_id
   FROM team_sets_teams tst
   INNER JOIN team_memberships team_memberships ON tst.team_id = team_memberships.team_id
   AND team_memberships.user_id = '2001ca8a-47ee-11e8-97c6-005056b01461'
   AND team_memberships.deleted = 0
   GROUP BY tst.team_set_id) calls_tf ON calls_tf.team_set_id = calls.team_set_id
LEFT JOIN calls_users calls_users ON (calls.id = calls_users.call_id)
AND (calls_users.deleted = ?)
LEFT JOIN users jt0_users ON (jt0_users.id = calls_users.user_id)
AND (jt0_users.deleted = ?)
LEFT JOIN users_cstm jt0_users_cstm ON jt0_users_cstm.id_c = jt0_users.id
LEFT JOIN users jt1_modified_user_link ON (calls.modified_user_id = jt1_modified_user_link.id)
AND (jt1_modified_user_link.deleted = ?)
LEFT JOIN users_cstm jt1_modified_user_link_cstm ON jt1_modified_user_link_cstm.id_c = jt1_modified_user_link.id
LEFT JOIN users jt2_created_by_link ON (calls.created_by = jt2_created_by_link.id)
AND (jt2_created_by_link.deleted = ?)
LEFT JOIN users_cstm jt2_created_by_link_cstm ON jt2_created_by_link_cstm.id_c = jt2_created_by_link.id
LEFT JOIN calls_contacts calls_contacts ON (calls.id = calls_contacts.call_id)
AND (calls_contacts.deleted = ?)
LEFT JOIN contacts jt3_contacts ON (jt3_contacts.id = calls_contacts.contact_id)
AND (jt3_contacts.deleted = ?)
LEFT JOIN contacts_cstm jt3_contacts_cstm ON jt3_contacts_cstm.id_c = jt3_contacts.id
LEFT JOIN subscriptions calls_following ON (calls.id = calls_following.parent_id)
AND (calls_following.deleted = ?)
AND (calls_following.parent_type = ?)
AND (calls_following.created_by = ?)
LEFT JOIN users jt4_following_link ON (jt4_following_link.id = calls_following.created_by)
AND (jt4_following_link.deleted = ?)
LEFT JOIN users_cstm jt4_following_link_cstm ON jt4_following_link_cstm.id_c = jt4_following_link.id
LEFT JOIN sugarfavorites calls_favorite ON (calls.id = calls_favorite.record_id)
AND (calls_favorite.deleted = ?)
AND (calls_favorite.module = ?)
AND (calls_favorite.created_by = ?)
LEFT JOIN users jt5_favorite_link ON (jt5_favorite_link.id = calls_favorite.modified_user_id)
AND (jt5_favorite_link.deleted = ?)
LEFT JOIN users_cstm jt5_favorite_link_cstm ON jt5_favorite_link_cstm.id_c = jt5_favorite_link.id
LEFT JOIN tag_bean_rel calls_tags ON (calls.id = calls_tags.bean_id)
AND (calls_tags.deleted = ?)
AND (calls_tags.bean_module = ?)
LEFT JOIN tags jt6_tag_link ON (jt6_tag_link.id = calls_tags.tag_id)
AND (jt6_tag_link.deleted = ?)
LEFT JOIN locked_field_bean_rel calls_locked_fields ON (calls.id = calls_locked_fields.bean_id)
AND (calls_locked_fields.deleted = ?)
AND (calls_locked_fields.bean_module = ?)
LEFT JOIN pmse_bpm_process_definition jt7_locked_fields_link ON (jt7_locked_fields_link.id = calls_locked_fields.pd_id)
AND (jt7_locked_fields_link.deleted = ?)
LEFT JOIN users jt8_assigned_user_link ON (calls.assigned_user_id = jt8_assigned_user_link.id)
AND (jt8_assigned_user_link.deleted = ?)
LEFT JOIN users_cstm jt8_assigned_user_link_cstm ON jt8_assigned_user_link_cstm.id_c = jt8_assigned_user_link.id
LEFT JOIN team_sets jt9_team_count_link ON (calls.team_set_id = jt9_team_count_link.id)
AND (jt9_team_count_link.deleted = ?)
LEFT JOIN amp_pitchingassignments_accounts_c amp_pitchingassignments_accounts ON amp_pitchingassignments_accounts.deleted = ?
LEFT JOIN amp_pitchingassignments jt10_amp_pitchingassignments_accounts ON (jt10_amp_pitchingassignments_accounts.id = amp_pitchingassignments_accounts.amp_pitchingassignments_accountsamp_pitchingassignments_ida)
AND (jt10_amp_pitchingassignments_accounts.deleted = ?)
LEFT JOIN amp_pitchingassignments_cstm jt10_amp_pitchingassignments_accounts_cstm ON jt10_amp_pitchingassignments_accounts_cstm.id_c = jt10_amp_pitchingassignments_accounts.id
LEFT JOIN calls_cstm calls_cstm ON calls_cstm.id_c = calls.id
WHERE ((calls.assigned_user_id = '2001ca8a-47ee-11e8-97c6-005056b01461')
       AND (calls.reminder_time >= ?)
       AND (calls.status IN (?,
                             ?))
       AND (calls_users.accept_status != ?)
       AND (calls.date_start BETWEEN ? AND ?)
       AND (jt0_users.id = ?))
  AND (calls.deleted = ?)
ORDER BY calls.date_modified DESC,
         calls.id DESC
LIMIT 21
OFFSET 0

I will greatly appreciate any insight into what might be causing the problem and what is the remedy -  any remarks on optimizing the db configuration are welcome, thanks!

Best regards,

Piotr

  • Hi Piotr G 

    I do not have a final solution, just some insights to help you improving the performance of this query.

    • User extended vardefs to create some indexes for fields evaluated on joins and where clauses;
    • Try to drop of from query the favorites and following, once there are a lots of records inside those tables and the left joins will widely multiply the amount of data to be processed by db. We have done that previously for some customers and the performance improved siginificantly
    • Try to remove from list view as related fields as possible, because once they are set to be selected SugarQuery will force left joins against their respective tables. Or you may customize those relationships in order to replace 'LEFT JOIN' by 'INNER JOIN' if you are confident the related fields will always be set.

    Kind regards

    André Lopes
    Lampada Global
    Skype: andre.lampada
  • We have encountered an issue occasionally with the MySQL block nested loop optimization. It is coming up more frequently in newer versions of Sugar.

    MySQL Bugs: #69721: Block Nested Loop making things slower 

     

    Try disabling block_nested_loop optimization to see if the situation stabilizes.

    From the Sugar 8.0 release notes:

    • Due to a MySQL performance optimizer bug, we recommend updating the config for your MySQL server to disable the 'block_nested_loop' optimization.
      SQL:
      SET SESSION optimizer_switch='block_nested_loop=off';
      MySQL cnf:
      [mysqld] optimizer-switch=block_nested_loop=off
      This can cause an increase in use of temporary files by MySQL. You may need to increase the open files limit on your system if you encounter an error like the following on Linux:
      Too many open files in system 
      For more information, refer to this easy EasyEngine tutorial.

    App Ecosystem @ SugarCRM

  • Just as a follow-up, it seems that indeed it was that MySQL bug mentioned above. After introducing the optimizer switch the problem seems to have gone away - no more queries stuck in creating sort index phase.