Project

General

Profile

Actions

Patch #30465

closed

Deadlock when assigning custom values

Added by Pavel Rosický about 5 years ago. Updated about 5 years ago.

Status:
Closed
Priority:
Normal
Category:
Performance
Target version:
Start date:
Due date:
% Done:

0%

Estimated time:

Description

There's been some changes in the new Rails version. It looks like deleting records from association is now scope aware.

After upgrading to Redmine 4.0, I've encountered several deadlocks under heavy load. Note that my DB has 30M+ records in custom_values.

ActiveRecord::Deadlocked: Mysql2::Error: Deadlock found when trying to get lock; try restarting transaction:
 DELETE FROM `custom_values` WHERE `custom_values`.`id` IN (SELECT `id` FROM
 (SELECT `custom_values`.`id` FROM `custom_values` LEFT OUTER JOIN `custom_fields` ON `custom_fields`.`id` = `custom_values`.`custom_field_id`
 WHERE `custom_values`.`customized_id` = 134661 AND
 `custom_values`.`customized_type` = 'Issue' AND `custom_values`.`id` IN
 (34100955, 34100961, 34100989, 34100990, 34100992) ORDER BY custom_fields.position) __active_record_temp)

the association looks like this

has_many :custom_values, lambda {includes(:custom_field).order("#{CustomField.table_name}.position")},
         :as => :customized,
         :inverse_of => :customized,
         :dependent => :delete_all,
         :validate => false

and it's populated at
https://github.com/redmine/redmine/blob/f5daae4041daa5ad6385f7d4cb43655c87515153/lib/plugins/acts_as_customizable/lib/acts_as_customizable.rb#L145

That's pretty nasty Rails magic. If you take a closer look at the query, it's clear that both includes(:custom_field) and order aren't necessary for deleting records (at least in this case).

the problem is that DELETE command locks the database and creating / updating a record like an issue is wrapped in a transaction.
https://github.com/redmine/redmine/blob/f5daae4041daa5ad6385f7d4cb43655c87515153/app/controllers/issues_controller.rb#L552

Ordering records in a subquery causes that many rows have to be locked in order to execute the query.
In my case this query took ~30s to execute under very heavy load. That's bad.

If duration of the whole transaction exceeded innodb_lock_wait_timeout (default value is 50), it fails as 500 internal server error.

After removing the order statement, the same query with the same conditions took ~0.1s and deadlocks were gone.

IMO, order and maybe even include(:custom_field) shouldn't be part of the association, you should always use an additional scope like #sorted if you want to get a sorted result.

The patch is simple and fixes the problem, but I have no idea how to write a test for it. It may also behave differently on other databases and even on mysql it's quite hard to replicate all conditions.

I tested it on

  Server version: 5.7.20-19-log Percona Server (GPL), Release '19'

please consider refactoring this association. Thanks!


Files

acts_as_customizable.rb.patch (770 Bytes) acts_as_customizable.rb.patch Pavel Rosický, 2019-01-18 19:50
Actions #1

Updated by Go MAEDA about 5 years ago

  • Target version set to 4.0.1
Actions #2

Updated by Jean-Philippe Lang about 5 years ago

  • Status changed from New to Closed
  • Assignee set to Jean-Philippe Lang

Committed, thanks.

Actions

Also available in: Atom PDF