Bug #10053
closedTable lock hangs all processes
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.
Updated by Jason Hane over 9 years ago
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 | +------+-------------+----------------------+--------+-----------------------------+--------------------------+---------+-------------------------------------------+------+----------+-----------------------------------------------------------+
Updated by Aaron Stone over 9 years ago
I think this is getting handled by #10228
Updated by Dominic Cleal over 9 years ago
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".
Updated by Marek Hulán over 8 years ago
- 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".
Updated by The Foreman Bot over 8 years ago
- Status changed from Assigned to Ready For Testing
- Pull request https://github.com/theforeman/foreman/pull/3392 added
Updated by Dominic Cleal over 8 years ago
- Has duplicate Bug #2778: Search in /reports without keyword make request never end on mysql added
Updated by Ivan Necas over 8 years ago
- Related to Bug #14503: Listing reports for a host via API/hammer consumes large amount of memory added
Updated by Marek Hulán over 8 years ago
- Status changed from Ready For Testing to Closed
- % Done changed from 0 to 100
Applied in changeset 2f1cc0f4b8e8d320e8eef309b1ab7c834b201dce.
Updated by Dominic Cleal over 8 years ago
- Translation missing: en.field_release set to 136