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:
mysql> show processlist;-----------+-----------+---------+---------+------+-------+------------------+
| Id | User | Host | db | Command | Time | State | Info |-----------+-----------+---------+---------+------+-------+------------------+
| 6 | root | localhost | redmine | Query | 0 | NULL | show processlist |
| 11 | redmine | localhost | redmine | Sleep | 255 | | NULL |
| 12 | redmine | localhost | redmine | Sleep | 552 | | NULL |
| 13 | redmine | localhost | redmine | Sleep | 544 | | NULL |
| 14 | redmine | localhost | redmine | Sleep | 1 | | NULL |-----------+-----------+---------+---------+------+-------+------------------+
5 rows in set (0.09 sec)
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.