HTTP 500/MySQL Timeout on Issue Update

Added by Brandon Franklin over 14 years ago

Hey all... Have a query: running redmine 0.9.4.stable on FreeBSD (out of ports) with a MySQL 5.1.47 backend. Redmine is a base install with the questions plugin enabled. Issue content was imported from a bugzilla instance using bz2redmine.rb.

We're now having a problem where redmine is hanging when attempting to update certain bugs. After these failed updates, the row (and possibly the issues table) is locked. I can unlock it by killing zombie sessions that are in a sleep state in the MySQL processlist -- e.g., it generally looks like:

The debug log gives this on a sample bad update:

Processing IssuesController#edit (for 10.10.2.67 at 2010-06-04 15:21:30) [POST]
Parameters: {"commit"=>"Submit", "notes"=>"already published - close.", "action"=>"edit", "authenticity_token"=>"4PApZBo5+PcTow6uopGB7UZEHKZhMR5kWrmi3ui7Y+w=", "id"=>"4856", "issue"=>{"start_date"=>"2010-0
1-14", "custom_field_values"=>{"6"=>"", "11"=>"Fail", "7"=>"", "12"=>"Fail", "8"=>"", "13"=>"Fail", "9"=>"Internal", "14"=>"Fail", "15"=>"Fail", "16"=>"Fail", "1"=>"", "17"=>"No", "2"=>"", "18"=>"", "3"=>"",
"19"=>"", "20"=>"", "4"=>"", "10"=>"Fail", "5"=>""}, "estimated_hours"=>"0.0", "priority_id"=>"3", "lock_version"=>"0", "fixed_version_id"=>"", "done_ratio"=>"100", "assigned_to_id"=>"", "subject"=>"VA Dev
2.0: Reports Pages GUI issue", "category_id"=>"144", "tracker_id"=>"1", "due_date"=>"", "description"=>"Inder the reports tab the Service, Administrative and Reporting Services pages do not appear to have a
left frame or left margin and are off center."}, "note"=>{"question_assigned_to"=>""}, "controller"=>"issues", "attachments"=>{"1"=>{"description"=>""}}}

ActiveRecord::StatementInvalid (Mysql::Error: Lock wait timeout exceeded; try restarting transaction: UPDATE `issues`
SET `fixed_version_id` = NULL, `lock_version` = 1, `assigned_to_id` = NULL, `done_ratio` = 100, `updated_on` = '2010-06-04 15:21:30'
WHERE id = 4856
AND `lock_version` = 0
):
app/controllers/issues_controller.rb:196:in `edit'
passenger (2.2.11) lib/phusion_passenger/rack/request_handler.rb:92:in `process_request'
passenger (2.2.11) lib/phusion_passenger/abstract_request_handler.rb:207:in `main_loop'
passenger (2.2.11) lib/phusion_passenger/railz/application_spawner.rb:418:in `start_request_handler'
passenger (2.2.11) lib/phusion_passenger/railz/application_spawner.rb:358:in `handle_spawn_application'
passenger (2.2.11) lib/phusion_passenger/utils.rb:184:in `safe_fork'
passenger (2.2.11) lib/phusion_passenger/railz/application_spawner.rb:354:in `handle_spawn_application'
passenger (2.2.11) lib/phusion_passenger/abstract_server.rb:352:in `__send__'
passenger (2.2.11) lib/phusion_passenger/abstract_server.rb:352:in `main_loop'
passenger (2.2.11) lib/phusion_passenger/abstract_server.rb:196:in `start_synchronously'
passenger (2.2.11) lib/phusion_passenger/abstract_server.rb:163:in `start'
passenger (2.2.11) lib/phusion_passenger/railz/application_spawner.rb:213:in `start'
passenger (2.2.11) lib/phusion_passenger/spawn_manager.rb:262:in `spawn_rails_application'
passenger (2.2.11) lib/phusion_passenger/abstract_server_collection.rb:126:in `lookup_or_add'
passenger (2.2.11) lib/phusion_passenger/spawn_manager.rb:256:in `spawn_rails_application'
passenger (2.2.11) lib/phusion_passenger/abstract_server_collection.rb:80:in `synchronize'
passenger (2.2.11) lib/phusion_passenger/abstract_server_collection.rb:79:in `synchronize'
passenger (2.2.11) lib/phusion_passenger/spawn_manager.rb:255:in `spawn_rails_application'
passenger (2.2.11) lib/phusion_passenger/spawn_manager.rb:154:in `spawn_application'
passenger (2.2.11) lib/phusion_passenger/spawn_manager.rb:287:in `handle_spawn_application'
passenger (2.2.11) lib/phusion_passenger/abstract_server.rb:352:in `__send__'
passenger (2.2.11) lib/phusion_passenger/abstract_server.rb:352:in `main_loop'
passenger (2.2.11) lib/phusion_passenger/abstract_server.rb:196:in `start_synchronously'

Rendering /usr/local/www/redmine/public/500.html (500 Internal Server Error)

One other little nugget of info: when we intentionally leave a required field missing, redmine kicks out an error related to the missing required field, and a bullet stating that a "Value is invalid", but not indicating which value. Any help is appreciated, even just some suggested next steps.

Replies (2)

RE: HTTP 500/MySQL Timeout on Issue Update - Added by Brandon Franklin over 14 years ago

Apologies for the formatting. The processlist output looks like:

mysql> show full processlist;
+----+---------+-----------+---------+---------+------+-------+-----------------------+
| Id | User    | Host      | db      | Command | Time | State | Info                  |
+----+---------+-----------+---------+---------+------+-------+-----------------------+
|  6 | root    | localhost | redmine | Query   |    0 | NULL  | show full processlist |
| 12 | redmine | localhost | redmine | Sleep   | 1050 |       | NULL                  |
| 13 | redmine | localhost | redmine | Sleep   | 1042 |       | NULL                  |
| 14 | redmine | localhost | redmine | Sleep   |    4 |       | NULL                  |
| 15 | redmine | localhost | redmine | Sleep   |    0 |       | NULL                  |
| 16 | redmine | localhost | redmine | Sleep   |    0 |       | NULL                  |
+----+---------+-----------+---------+---------+------+-------+-----------------------+
6 rows in set (0.02 sec)

RE: HTTP 500/MySQL Timeout on Issue Update - Added by Felix Schäfer over 14 years ago

The mysql gem doesn't support MySQL 5.1 yet AFAIK.

(1-2/2)

Project

General

Profile

Redmine