Bug #10053
closed
Table lock hangs all processes
Added by Jason Hane over 9 years ago.
Updated over 6 years ago.
Description
We have an issue that occurs frequently that causes all available Passenger threads to wait on the database. In the database there is one query that locks several tables causing a backlog of connections to hang rendering Foreman unresponsive. The database is MySQL.
This is the query causing the locks. It's been running for almost 2 hours.
SELECT DISTINCT `reports`.id FROM `reports`
LEFT OUTER JOIN `hosts` ON `hosts`.`id` = `reports`.`host_id` AND
`hosts`.`type` IN ('Host::Managed')
LEFT OUTER JOIN `hosts` `hosts_reports_join` ON `hosts_reports_join`.`id` = `reports`.`host_id` AND
`hosts_reports_join`.`type` IN ('Host::Managed')
LEFT OUTER JOIN `environments` ON `environments`.`id` = `hosts_reports_join`.`environment_id`
LEFT OUTER JOIN `logs` ON `logs`.`report_id` = `reports`.`id`
LEFT OUTER JOIN `messages` ON `messages`.`id` = `logs`.`message_id`
LEFT OUTER JOIN `logs` `logs_reports_join` ON `logs_reports_join`.`report_id` = `reports`.`id`
LEFT OUTER JOIN `sources` ON `sources`.`id` = `logs_reports_join`.`source_id`
LEFT OUTER JOIN `hosts` `hosts_reports_join_2` ON `hosts_reports_join_2`.`id` = `reports`.`host_id` AND
`hosts_reports_join_2`.`type` IN ('Host::Managed')
LEFT OUTER JOIN `hostgroups` ON `hostgroups`.`id` = `hosts_reports_join_2`.`hostgroup_id`
WHERE `reports`.`host_id` IN (
SELECT `hosts`.`id` FROM `hosts`
WHERE `hosts`.`type` IN ('Host::Managed')) AND
(((((`reports`.`status` >> 0 & 16777215) > 0)) AND
(`hosts`.`name` LIKE '%applied%' OR
`environments`.`name` LIKE '%applied%' OR
`messages`.`value` LIKE '%applied%' OR
`sources`.`value` LIKE '%applied%' OR
`hostgroups`.`name` LIKE '%applied%' OR
`hostgroups`.`title` LIKE '%applied%' OR
`hostgroups`.`title` LIKE '%applied%'))
)
ORDER BY `reports`.`reported_at` DESC LIMIT 150 OFFSET 0
These are the last entries in the production.log.
Started POST "/api/reports" for 10.48.184.55 at 2015-04-07 15:35:28 +0000
Processing by Api::V2::ReportsController#create as JSON
Parameters: {"report"=>"[FILTERED]", "apiv"=>"v2"}
processing report for lvsdevwsv02-01.us.gspt.net
Connecting to database specified by database.yml
Connecting to database specified by database.yml
Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
Creating scope :completer_scope. Overwriting existing method Location.completer_scope.
Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
Creating scope :completer_scope. Overwriting existing method Location.completer_scope.
Connecting to database specified by database.yml
Connecting to database specified by database.yml
Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
Creating scope :completer_scope. Overwriting existing method Location.completer_scope.
Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
Creating scope :completer_scope. Overwriting existing method Location.completer_scope.
Connecting to database specified by database.yml
Connecting to database specified by database.yml
Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
Creating scope :completer_scope. Overwriting existing method Location.completer_scope.
Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
Creating scope :completer_scope. Overwriting existing method Location.completer_scope.
Here is the explain plan.
+------+-------------+----------------------+--------+-----------------------------+--------------------------+---------+-------------------------------------------+------+----------+-----------------------------------------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+------+-------------+----------------------+--------+-----------------------------+--------------------------+---------+-------------------------------------------+------+----------+-----------------------------------------------------------+
| 1 | PRIMARY | hosts | ref | PRIMARY,index_hosts_on_type | index_hosts_on_type | 258 | const | 371 | 100.00 | Using where; Using index; Using temporary; Using filesort |
| 1 | PRIMARY | reports | ref | index_reports_on_host_id | index_reports_on_host_id | 4 | foreman.hosts.id | 1075 | 100.00 | Using where |
| 1 | PRIMARY | hosts | eq_ref | PRIMARY,index_hosts_on_type | PRIMARY | 4 | foreman.hosts.id | 1 | 100.00 | Using where; Distinct |
| 1 | PRIMARY | hosts_reports_join | eq_ref | PRIMARY,index_hosts_on_type | PRIMARY | 4 | foreman.hosts.id | 1 | 100.00 | Using where; Distinct |
| 1 | PRIMARY | environments | eq_ref | PRIMARY | PRIMARY | 4 | foreman.hosts_reports_join.environment_id | 1 | 100.00 | Using where; Distinct |
| 1 | PRIMARY | logs | ref | index_logs_on_report_id | index_logs_on_report_id | 5 | foreman.reports.id | 19 | 100.00 | Distinct |
| 1 | PRIMARY | messages | eq_ref | PRIMARY | PRIMARY | 4 | foreman.logs.message_id | 1 | 100.00 | Using where; Distinct |
| 1 | PRIMARY | logs_reports_join | ref | index_logs_on_report_id | index_logs_on_report_id | 5 | foreman.reports.id | 19 | 100.00 | Distinct |
| 1 | PRIMARY | sources | eq_ref | PRIMARY | PRIMARY | 4 | foreman.logs_reports_join.source_id | 1 | 100.00 | Using where; Distinct |
| 1 | PRIMARY | hosts_reports_join_2 | eq_ref | PRIMARY,index_hosts_on_type | PRIMARY | 4 | foreman.hosts.id | 1 | 100.00 | Using where; Distinct |
| 1 | PRIMARY | hostgroups | eq_ref | PRIMARY | PRIMARY | 4 | foreman.hosts_reports_join_2.hostgroup_id | 1 | 100.00 | Using where; Distinct |
+------+-------------+----------------------+--------+-----------------------------+--------------------------+---------+-------------------------------------------+------+----------+-----------------------------------------------------------+
I think this is getting handled by #10228
I'm not sure if the source_id index will help here, the slow bit is probably the wildcard queries on those report message/source values. The query looks like one caused by the search box on the reports page, if you had just typed in "applied".
- Status changed from New to Assigned
- Assignee set to Marek Hulán
The issue is caused by the fact that we try to search the query through all logs (message and source attributes), in this case it was applied. We should avoid using these attributes in generic search since the resulting set after all OUTER JOINS is too big. If user wants to find reports based on message they should explicitly ask for "log = applied".
- Status changed from Assigned to Ready For Testing
- Pull request https://github.com/theforeman/foreman/pull/3392 added
- Bugzilla link set to 1324450
- Has duplicate Bug #2778: Search in /reports without keyword make request never end on mysql added
- Related to Bug #14503: Listing reports for a host via API/hammer consumes large amount of memory added
- Status changed from Ready For Testing to Closed
- % Done changed from 0 to 100
- Translation missing: en.field_release set to 136
Also available in: Atom
PDF