Bug #10053
Table lock hangs all processes
Pull request:
Fixed in Releases:
Found in Releases:
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.
Related issues
Associated revisions
History
#1
Updated by Jason Hane almost 6 years ago
Updated by 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 | +------+-------------+----------------------+--------+-----------------------------+--------------------------+---------+-------------------------------------------+------+----------+-----------------------------------------------------------+
#2
Updated by Aaron Stone over 5 years ago
Updated by I think this is getting handled by #10228
#3
Updated by Dominic Cleal over 5 years ago
Updated by 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".
#4
Updated by Marek Hulán almost 5 years ago
Updated by - 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".
#5
Updated by The Foreman Bot almost 5 years ago
Updated by - Status changed from Assigned to Ready For Testing
- Pull request https://github.com/theforeman/foreman/pull/3392 added
#6
Updated by Marek Hulán almost 5 years ago
- Bugzilla link set to 1324450
#7
Updated by Dominic Cleal almost 5 years ago
- Has duplicate Bug #2778: Search in /reports without keyword make request never end on mysql added
#8
Updated by Ivan Necas almost 5 years ago
Updated by - Related to Bug #14503: Listing reports for a host via API/hammer consumes large amount of memory added
#9
Updated by Marek Hulán almost 5 years ago
- Status changed from Ready For Testing to Closed
- % Done changed from 0 to 100
Applied in changeset 2f1cc0f4b8e8d320e8eef309b1ab7c834b201dce.
#10
Updated by Dominic Cleal almost 5 years ago
- Legacy Backlogs Release (now unused) set to 136
Fixes #10053 - search in logs must be explicit