Very slow query stalling system

[dugjohnson]

We are getting intermittent timing issues in that a user will send an email and sometimes it works quickly and sometimes it will take 20ish seconds to give back control. And this is affecting the whole server. I've been logged in to the CLI on the server and it would stop responding for about that amount of time...then be back to normal.
I've turned on slow query log in mysql and there are 15-20 second queries that involve note and subscription tables in a large statement involving multiple UNIONS. I believe it is coming from the EmailNotification.php but not completely sure. I turned off all notifications in administration as a test, but those queries keep on happening.

Question...

Is there a way to turn off notifcations to test if this is what is causing the slow queries?

and

Is there another way I should be tracking down where the queries are coming from? The statements appear to be built in code so it's kind of tough to track based on the actual query I have captured

[dugjohnson]

If it helps

(
SELECT note.id AS `id`, note.number AS `number`, note.type AS `type`, note.post AS `post`, note.data AS `data`, note.parent_type AS `parentType`, note.parent_id AS `parentId`, note.related_type AS `relatedType`, note.related_id AS `relatedId`, note.target_type AS `targetType`, note.created_at AS `createdAt`, note.created_by_id AS `createdById`, TRIM(CONCAT(createdBy.first_name, ' ', createdBy.last_name)) AS `createdByName`, note.is_global AS `isGlobal`, note.is_internal AS `isInternal`, createdBy.gender AS `createdByGender` FROM `note` USE INDEX (`IDX_CREATED_BY_NUMBER`) JOIN `subscription` AS `subscription` ON subscription.entity_type = note.parent_type AND subscription.entity_id = note.parent_id AND subscription.user_id = '59034f2cd441568f3' LEFT JOIN `user` AS `createdBy` ON note.created_by_id = createdBy.id WHERE (((note.related_id IS NOT NULL AND note.related_type NOT IN ('Email','TargetList')) OR (note.related_id IS NULL))) AND (((note.related_type IS NULL OR note.related_type NOT IN ('User','BpmnUserTask'))) AND ((note.parent_type IS NULL OR note.parent_type NOT IN ('User','BpmnUserTask')))) AND (note.created_by_id <> '59034f2cd441568f3') AND note.deleted = '0' ORDER BY note.number DESC LIMIT 0, 11
)
 UNION ALL 
(
SELECT DISTINCT note.id AS `id`, note.number AS `number`, note.type AS `type`, note.post AS `post`, note.data AS `data`, note.parent_type AS `parentType`, note.parent_id AS `parentId`, note.related_type AS `relatedType`, note.related_id AS `relatedId`, note.target_type AS `targetType`, note.created_at AS `createdAt`, note.created_by_id AS `createdById`, TRIM(CONCAT(createdBy.first_name, ' ', createdBy.last_name)) AS `createdByName`, note.is_global AS `isGlobal`, note.is_internal AS `isInternal`, createdBy.gender AS `createdByGender` FROM `note` USE INDEX (`IDX_CREATED_BY_NUMBER`) JOIN `subscription` AS `subscription` ON subscription.entity_type = note.parent_type AND subscription.entity_id = note.parent_id AND subscription.user_id = '59034f2cd441568f3' LEFT JOIN `user` AS `createdBy` ON note.created_by_id = createdBy.id LEFT JOIN `note_team` AS `noteTeam` ON noteTeam.note_id = note.id AND noteTeam.deleted = '' LEFT JOIN `note_user` AS `noteUser` ON noteUser.note_id = note.id AND noteUser.deleted = '' WHERE ((note.related_id IS NOT NULL AND note.related_type IN ('Email','TargetList')) AND ((noteTeam.team_id IN ('5624f88064f06477f','547bf867bc516') OR noteUser.user_id = '59034f2cd441568f3'))) AND (((note.related_type IS NULL OR note.related_type NOT IN ('User','BpmnUserTask'))) AND ((note.parent_type IS NULL OR note.parent_type NOT IN ('User','BpmnUserTask')))) AND (note.created_by_id <> '59034f2cd441568f3') AND note.deleted = '0' ORDER BY note.number DESC LIMIT 0, 11
)
 UNION ALL 
(
SELECT note.id AS `id`, note.number AS `number`, note.type AS `type`, note.post AS `post`, note.data AS `data`, note.parent_type AS `parentType`, note.parent_id AS `parentId`, note.related_type AS `relatedType`, note.related_id AS `relatedId`, note.target_type AS `targetType`, note.created_at AS `createdAt`, note.created_by_id AS `createdById`, TRIM(CONCAT(createdBy.first_name, ' ', createdBy.last_name)) AS `createdByName`, note.is_global AS `isGlobal`, note.is_internal AS `isInternal`, createdBy.gender AS `createdByGender` FROM `note` USE INDEX (`IDX_CREATED_BY_NUMBER`) JOIN `subscription` AS `subscription` ON subscription.entity_type = note.super_parent_type AND subscription.entity_id = note.super_parent_id AND subscription.user_id = '59034f2cd441568f3' LEFT JOIN `user` AS `createdBy` ON note.created_by_id = createdBy.id WHERE ((note.parent_id <> note.super_parent_id OR note.parent_type <> note.super_parent_type)) AND (((note.related_id IS NOT NULL AND note.related_type NOT IN ('Email','TargetList')) OR (note.related_id IS NULL AND note.parent_type NOT IN ('Email','TargetList')))) AND (((note.related_type IS NULL OR note.related_type NOT IN ('User','BpmnUserTask'))) AND ((note.parent_type IS NULL OR note.parent_type NOT IN ('User','BpmnUserTask')))) AND (note.created_by_id <> '59034f2cd441568f3') AND note.deleted = '0' ORDER BY note.number DESC LIMIT 0, 11
)
 UNION ALL 
(
SELECT DISTINCT note.id AS `id`, note.number AS `number`, note.type AS `type`, note.post AS `post`, note.data AS `data`, note.parent_type AS `parentType`, note.parent_id AS `parentId`, note.related_type AS `relatedType`, note.related_id AS `relatedId`, note.target_type AS `targetType`, note.created_at AS `createdAt`, note.created_by_id AS `createdById`, TRIM(CONCAT(createdBy.first_name, ' ', createdBy.last_name)) AS `createdByName`, note.is_global AS `isGlobal`, note.is_internal AS `isInternal`, createdBy.gender AS `createdByGender` FROM `note` USE INDEX (`IDX_CREATED_BY_NUMBER`) JOIN `subscription` AS `subscription` ON subscription.entity_type = note.super_parent_type AND subscription.entity_id = note.super_parent_id AND subscription.user_id = '59034f2cd441568f3' LEFT JOIN `user` AS `createdBy` ON note.created_by_id = createdBy.id LEFT JOIN `note_team` AS `noteTeam` ON noteTeam.note_id = note.id AND noteTeam.deleted = '' LEFT JOIN `note_user` AS `noteUser` ON noteUser.note_id = note.id AND noteUser.deleted = '' WHERE ((note.parent_id <> note.super_parent_id OR note.parent_type <> note.super_parent_type)) AND (((note.related_id IS NOT NULL AND note.related_type IN ('Email','TargetList')) OR (note.related_id IS NULL AND note.parent_type IN ('Email','TargetList'))) AND ((noteTeam.team_id IN ('5624f88064f06477f','547bf867bc516') OR noteUser.user_id = '59034f2cd441568f3'))) AND (((note.related_type IS NULL OR note.related_type NOT IN ('User','BpmnUserTask'))) AND ((note.parent_type IS NULL OR note.parent_type NOT IN ('User','BpmnUserTask')))) AND (note.created_by_id <> '59034f2cd441568f3') AND note.deleted = '0' ORDER BY note.number DESC LIMIT 0, 11
)
 UNION ALL 
(
SELECT note.id AS `id`, note.number AS `number`, note.type AS `type`, note.post AS `post`, note.data AS `data`, note.parent_type AS `parentType`, note.parent_id AS `parentId`, note.related_type AS `relatedType`, note.related_id AS `relatedId`, note.target_type AS `targetType`, note.created_at AS `createdAt`, note.created_by_id AS `createdById`, TRIM(CONCAT(createdBy.first_name, ' ', createdBy.last_name)) AS `createdByName`, note.is_global AS `isGlobal`, note.is_internal AS `isInternal`, createdBy.gender AS `createdByGender` FROM `note` LEFT JOIN `user` AS `createdBy` ON note.created_by_id = createdBy.id WHERE note.created_by_id = '59034f2cd441568f3' AND note.parent_id IS NULL AND note.type = 'Post' AND note.is_global = '' AND (((note.related_type IS NULL OR note.related_type NOT IN ('User','BpmnUserTask'))) AND ((note.parent_type IS NULL OR note.parent_type NOT IN ('User','BpmnUserTask')))) AND note.deleted = '0' ORDER BY note.number DESC LIMIT 0, 11
)
 UNION ALL 
(
SELECT note.id AS `id`, note.number AS `number`, note.type AS `type`, note.post AS `post`, note.data AS `data`, note.parent_type AS `parentType`, note.parent_id AS `parentId`, note.related_type AS `relatedType`, note.related_id AS `relatedId`, note.target_type AS `targetType`, note.created_at AS `createdAt`, note.created_by_id AS `createdById`, TRIM(CONCAT(createdBy.first_name, ' ', createdBy.last_name)) AS `createdByName`, note.is_global AS `isGlobal`, note.is_internal AS `isInternal`, createdBy.gender AS `createdByGender` FROM `note` LEFT JOIN `note_user` AS `usersMiddle` ON note.id = usersMiddle.note_id AND usersMiddle.deleted = '0' LEFT JOIN `user` AS `users` ON users.id = usersMiddle.user_id AND users.deleted = '0' LEFT JOIN `user` AS `createdBy` ON note.created_by_id = createdBy.id WHERE note.created_by_id <> '59034f2cd441568f3' AND usersMiddle.user_id = '59034f2cd441568f3' AND note.parent_id IS NULL AND note.type = 'Post' AND note.is_global = '' AND (((note.related_type IS NULL OR note.related_type NOT IN ('User','BpmnUserTask'))) AND ((note.parent_type IS NULL OR note.parent_type NOT IN ('User','BpmnUserTask')))) AND (note.created_by_id <> '59034f2cd441568f3') AND note.deleted = '0' ORDER BY note.number DESC LIMIT 0, 11
)
 UNION ALL 
(
SELECT note.id AS `id`, note.number AS `number`, note.type AS `type`, note.post AS `post`, note.data AS `data`, note.parent_type AS `parentType`, note.parent_id AS `parentId`, note.related_type AS `relatedType`, note.related_id AS `relatedId`, note.target_type AS `targetType`, note.created_at AS `createdAt`, note.created_by_id AS `createdById`, TRIM(CONCAT(createdBy.first_name, ' ', createdBy.last_name)) AS `createdByName`, note.is_global AS `isGlobal`, note.is_internal AS `isInternal`, createdBy.gender AS `createdByGender` FROM `note` LEFT JOIN `user` AS `createdBy` ON note.created_by_id = createdBy.id WHERE note.parent_id IS NULL AND note.type = 'Post' AND note.is_global = '1' AND (((note.related_type IS NULL OR note.related_type NOT IN ('User','BpmnUserTask'))) AND ((note.parent_type IS NULL OR note.parent_type NOT IN ('User','BpmnUserTask')))) AND note.deleted = '0' ORDER BY note.number DESC LIMIT 0, 11
)
)
            ORDER BY number DESC
         LIMIT 0, 11;

[yuri]

Hi Doug,

This query is executed when Stream dashlet is displayed.

[dugjohnson]

Thanks. I'll look there.
Any idea why it might be taking 18 seconds (variably) to execute? I know we have a lot of data but I would expect I might be able to adjust indexing to make that be performant.

[yuri]

No sure that indexes will help in this case. The query is quite optimized. If you find a solution please let me know.

I suggest running each sub-query separately with SQL_NO_CACHE parameter for testing. I believe, the first two are the slowest. Big "subscription" table is the problem. How much entries does it have?

BTW: You will need to add indexes to entityDefs, because indexes that are not defined will be dropped after rebuild. Example: https://github.com/espocrm/espocrm/b...Note.json#L159 , but you will need to add it in custom/Espo/Resources/metadata/entityDefs/.

[dugjohnson]

There are 191380 subscription records.
Looks like I need to do some digging.
I've not gone into the subscription usage before. Is it safe to remove subscription records of users that are no longer active (they are gone).

[yuri]

> Is it safe to remove subscription records of users that are no longer active

Yes.

[dugjohnson]

I've now done the analysis on the SQL statement(s) and the speed issue is happening because of our large count of note records.
The first portion of the query (the first union) is pulling approx 6000 records from 1.2 M records, then ordering by number DESC, then limiting to 11 records. In checking examine, this is using filesort. This takes 4 seconds. And it is the case for each of the portions of the join which is why the time adds up...
If I remove the order by clause, it takes 0.05 seconds.
I thought about creating an index on number DESC, but mysql doesn't support DESC indexes.
I found that if I create a temporary table of the last 50000 records and then run the portion against THAT, it only takes 0.38 seconds.

My thought would be to update Stream.php (or create a custom one) that creates a temporary table from the last 50000 records from note and then runs the query against that.

It looks like I'd need to make the changes in FindUserStream method.

What I can't figure out is how to change the access to 'Note' to access a temp table that I will create.

Can you point me to an example of code anywhere that uses the ORM and a temporary table?
or
Based on what I've discovered, do you have any other suggestions that I might have missed?

[yuri]

ORM doesn't support temporary tables.

I don't understand how temporary table can be utilized. New entries are added into note table often. Data will be not actual, the point of Stream, showing last records, will be lost.

MySQL 8 should support desc indexes now. I tested desc index, and didn't notice any performance boost.

What mysql version do you have? Did you try to use index number instead of 'IDX_CREATED_BY_NUMBER'? On mysql 8 it's twice faster when using number index.

[dugjohnson]

Creating a temporary table temp_note made up of the latest 50000 records each time before calling the large join, then dropping it afterwards would keep the data current. And save about 12 of the 15 seconds I'm experiencing.
I'm talking a true temporary table, as one might use in a script. As in
CREATE TEMPORARY TABLE temp_note as (SELECT * from note ORDER by number DESC LIMIT 0, 50000)
thus getting only one hit on the Order by rather than several
But if it isn't available it isn't available.
But I have not tried the other index and will do so.
If that doesn't work then copying older notes to an archive so that they can still be available is my next alternative.

[dugjohnson]

I'm running MariaDB version 10.1.41.
The number index speeds things up dramatically.
Testing on live now...

[dugjohnson]

Changing the index to `number` caused the queries to no longer hit the "long query" log, so that should be that. Thanks.

Getting rid of THOSE long queries stopped masking another long query that is happening much less frequently on email, but I'm applying the same method there.
Again, thanks yuri

[yuri]

Could you provide more details what happened with emails and how you solved it? Thanks.

The problem that the same indexing may result to performance drop or raise depending on database version. One index gives a benefit on mysql 5.7, but it won't be beneficial on 8.0, plus we also have mariadb to support.

[rodrigocoelho]

I just upgraded my mysql from version 5.7 to 8.0. Now, my emails filtering is taking not less than 40 seconds. Before, it was something like 3 seconds.

What should I do? Any recommendations?

Thanks

[espcrm]

Go back to 5.7 I would say, EspoCRM 5.8 isn't build/optimize for MySQL 8 yet I believe, so it might not be using any or little of the feature available.MySQL8 provide.