Defect #23878

Closing all subtasks causes error if default priority is not defined and priority is derived from subtasks

Added by Pavel Potcheptsov 11 months ago. Updated 11 months ago.

Status:ClosedStart date:
Priority:NormalDue date:
Assignee:Jean-Philippe Lang% Done:

0%

Category:Issues
Target version:3.3.1
Resolution:Fixed Affected version:3.3.0

Description

Others tasks are closing normally but this one throws an error.

Redmine 3.3.0.stable.15842
Environment:
  Redmine version                3.3.0.stable.15842
  Ruby version                   1.9.3-p327 (2012-11-10) [i686-linux]
  Rails version                  4.2.7.1
  Environment                    production
  Database adapter               Mysql2
SCM:
  Subversion                     1.8.8
  Git                            1.7.1
  Filesystem                     
Redmine plugins:
  advanced_roadmap_v2            2.4.3
  redmine_agile                  1.4.1
  redmine_checklists             3.1.5
  redmine_lightbox2              0.3.1
  redmine_timesheet_plugin       0.7.0
  redmine_xls_export             0.2.1.t9

Started PATCH "/issues/22964/edit.js" for 127.0.0.1 at 2016-09-21 09:14:15 +0200
Processing by IssuesController#edit as JS
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"**********", "form_update_triggered_by"=>"issue_status_id", "issue"=>{"is_private"=>"0", "project_id"=>"657", "tracker_id"=>"4", "subject"=>"************", "description"=>"", "status_id"=>"5", "priority_id"=>"4", "assigned_to_id"=>"213", "fixed_version_id"=>"956", "parent_issue_id"=>"22746", "start_date"=>"2016-09-02", "due_date"=>"2016-09-02", "estimated_hours"=>"8.0", "done_ratio"=>"100", "checklists_attributes"=>{"0"=>{"is_done"=>"0", "subject"=>"", "_destroy"=>"false", "position"=>"1", "id"=>""}}, "notes"=>"", "private_notes"=>"0", "lock_version"=>"11"}, "time_entry"=>{"hours"=>"", "activity_id"=>"20", "user_id"=>"95", "comments"=>""}, "last_journal_id"=>"152098", "id"=>"22964"}
  Current user: ppo (id=95)
  Rendered issues/_form_custom_fields.html.erb (0.1ms)
  Rendered issues/_attributes.html.erb (17.9ms)
  Rendered plugins/redmine_agile/app/views/issues/_issue_story_points_form.html.erb (0.1ms)
  Rendered plugins/redmine_agile/app/views/issues/_agile_data_fields.html.erb (0.3ms)
  Rendered plugins/redmine_checklists/app/views/issues/_checklist_fields.html.erb (1.1ms)
  Rendered plugins/redmine_checklists/app/views/issues/_checklist_fields.html.erb (0.9ms)
  Rendered plugins/redmine_checklists/app/views/issues/_checklist_form.html.erb (4.4ms)
  Rendered issues/_form.html.erb (65.1ms)
  Rendered issues/edit.js.erb (67.5ms)
Completed 200 OK in 120ms (Views: 66.1ms | ActiveRecord: 11.1ms)
Started GET "/time_loggers/render_menu?_=1474385709357" for 127.0.0.1 at 2016-09-21 09:14:18 +0200

Started PATCH "/issues/22964" for 127.0.0.1 at 2016-09-21 09:14:19 +0200
Processing by IssuesController#update as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"******", "form_update_triggered_by"=>"", "issue"=>{"is_private"=>"0", "project_id"=>"657", "tracker_id"=>"4", "subject"=>"********", "description"=>"", "status_id"=>"5", "priority_id"=>"4", "assigned_to_id"=>"213", "fixed_version_id"=>"956", "parent_issue_id"=>"22746", "start_date"=>"2016-09-02", "due_date"=>"2016-09-02", "estimated_hours"=>"8.0", "done_ratio"=>"100", "notes"=>"", "private_notes"=>"0", "lock_version"=>"11"}, "time_entry"=>{"hours"=>"", "activity_id"=>"20", "user_id"=>"95", "comments"=>""}, "last_journal_id"=>"152098", "commit"=>"Submit", "id"=>"22964"}
  Current user: ppo (id=95)
Completed 500 Internal Server Error in 227ms (ActiveRecord: 149.4ms)

ActiveRecord::StatementInvalid (Mysql2::Error: Column 'priority_id' cannot be null: UPDATE `issues` SET `issues`.`priority_id` = NULL, `issues`.`updated_on` = '2016-09-21 09:14:19', `issues`.`lock_version` = 36 WHERE `issues`.`id` = 22746 AND `issues`.`lock_version` = 35):
  app/models/issue.rb:210:in `create_or_update'
  app/models/issue.rb:1567:in `recalculate_attributes_for'
  app/models/issue.rb:1523:in `update_parent_attributes'
  app/models/issue.rb:210:in `create_or_update'
  app/controllers/issues_controller.rb:515:in `block in save_issue_with_child_records'
  app/controllers/issues_controller.rb:503:in `save_issue_with_child_records'
  app/controllers/issues_controller.rb:179:in `update'
  lib/redmine/sudo_mode.rb:63:in `sudo_mode'

redmine_close_task.png (84.7 KB) Pavel Potcheptsov, 2016-09-21 09:27

Associated revisions

Revision 15857
Added by Jean-Philippe Lang 11 months ago

Closing all subtasks causes error if default priority is not defined and priority is derived from subtasks (#23878).

History

#1 Updated by Toshi MARUYAMA 11 months ago

  • Status changed from New to Closed
  • Resolution set to Invalid

Mysql2::Error: Column 'priority_id' cannot be null:

As log says, Redmine core does set priority null.
Your plugin causes it.

#2 Updated by Pavel Potcheptsov 11 months ago

I was able to reproduce without plugins: Create issue, create subtask and assign it, then change status and on the close it fails.

# ruby ./bin/about 

Environment:
  Redmine version                3.3.0.stable.15732
  Ruby version                   1.9.3-p327 (2012-11-10) [i686-linux]
  Rails version                  4.2.6
  Environment                    production
  Database adapter               Mysql2
SCM:
  Subversion                     1.8.8
  Git                            1.7.1
  Filesystem                     
Redmine plugins:
  no plugin installed

# tail -n 50  log/production.log 

Started GET "/issues/18256" for 127.0.0.1 at 2016-09-21 14:23:47 +0300
Processing by IssuesController#show as HTML
  Parameters: {"id"=>"18256"}
  Current user: ppo (id=95)
  Rendered issues/_action_menu.html.erb (4.3ms)
  Rendered issue_relations/_form.html.erb (2.3ms)
  Rendered issues/_relations.html.erb (3.4ms)
  Rendered issues/_action_menu.html.erb (3.5ms)
  Rendered issues/_form_custom_fields.html.erb (1.5ms)
  Rendered issues/_attributes.html.erb (25.2ms)
  Rendered issues/_form.html.erb (96.4ms)
  Rendered attachments/_form.html.erb (2.7ms)
  Rendered issues/_edit.html.erb (366.8ms)
  Rendered issues/_sidebar.html.erb (7.5ms)
  Rendered watchers/_watchers.html.erb (3.4ms)
  Rendered issues/show.html.erb within layouts/base (559.1ms)
Completed 200 OK in 677ms (Views: 416.2ms | ActiveRecord: 190.3ms)
Started PATCH "/issues/18256/edit.js" for 127.0.0.1 at 2016-09-21 14:26:35 +0300
Processing by IssuesController#edit as JS
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"zOohZFn5pbDzVhvKxCAOvVgK3GYxuPxK9r23Xl53ThGc/HT1/eJbc6k64eyHRIxBLVD6A7mE1IiKOih7JY+a8A==", "form_update_triggered_by"=>"issue_status_id", "issue"=>{"is_private"=>"0", "project_id"=>"78", "tracker_id"=>"4", "subject"=>"Child issue", "description"=>"", "status_id"=>"5", "priority_id"=>"3", "assigned_to_id"=>"95", "category_id"=>"", "parent_issue_id"=>"18255", "start_date"=>"2016-09-21", "due_date"=>"", "estimated_hours"=>"", "done_ratio"=>"0", "custom_field_values"=>{"23"=>"", "30"=>""}, "notes"=>"", "private_notes"=>"0", "lock_version"=>"0"}, "time_entry"=>{"hours"=>"", "activity_id"=>"20", "user_id"=>"95", "comments"=>""}, "last_journal_id"=>"", "next_issue_id"=>"18255", "issue_position"=>"1", "issue_count"=>"11", "id"=>"18256"}
  Current user: ppo (id=95)
  Rendered issues/_form_custom_fields.html.erb (3.1ms)
  Rendered issues/_attributes.html.erb (26.8ms)
  Rendered issues/_form.html.erb (103.1ms)
  Rendered issues/edit.js.erb (251.5ms)
Completed 200 OK in 342ms (Views: 248.2ms | ActiveRecord: 16.8ms)
Started PATCH "/issues/18256" for 127.0.0.1 at 2016-09-21 14:26:37 +0300
Processing by IssuesController#update as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"zOohZFn5pbDzVhvKxCAOvVgK3GYxuPxK9r23Xl53ThGc/HT1/eJbc6k64eyHRIxBLVD6A7mE1IiKOih7JY+a8A==", "form_update_triggered_by"=>"", "issue"=>{"is_private"=>"0", "project_id"=>"78", "tracker_id"=>"4", "subject"=>"Child issue", "description"=>"", "status_id"=>"5", "priority_id"=>"3", "assigned_to_id"=>"95", "category_id"=>"", "parent_issue_id"=>"18255", "start_date"=>"2016-09-21", "due_date"=>"", "estimated_hours"=>"", "done_ratio"=>"0", "custom_field_values"=>{"23"=>"", "30"=>""}, "notes"=>"", "private_notes"=>"0", "lock_version"=>"0"}, "time_entry"=>{"hours"=>"", "activity_id"=>"20", "user_id"=>"95", "comments"=>""}, "last_journal_id"=>"", "commit"=>"Submit", "next_issue_id"=>"18255", "issue_position"=>"1", "issue_count"=>"11", "id"=>"18256"}
  Current user: ppo (id=95)
Completed 500 Internal Server Error in 175ms (ActiveRecord: 60.3ms)

ActiveRecord::StatementInvalid (Mysql2::Error: Column 'priority_id' cannot be null: UPDATE `issues` SET `issues`.`priority_id` = NULL, `issues`.`done_ratio` = 100, `issues`.`updated_on` = '2016-09-21 14:26:37', `issues`.`lock_version` = 1 WHERE `issues`.`id` = 18255 AND `issues`.`lock_version` = 0):
  app/models/issue.rb:210:in `create_or_update'
  app/models/issue.rb:1566:in `recalculate_attributes_for'
  app/models/issue.rb:1522:in `update_parent_attributes'
  app/models/issue.rb:210:in `create_or_update'
  app/controllers/issues_controller.rb:512:in `block in save_issue_with_child_records'
  app/controllers/issues_controller.rb:500:in `save_issue_with_child_records'
  app/controllers/issues_controller.rb:179:in `update'
  lib/redmine/sudo_mode.rb:63:in `sudo_mode'

#3 Updated by Toshi MARUYAMA 11 months ago

Toshi MARUYAMA wrote:

Mysql2::Error: Column 'priority_id' cannot be null:

As log says, Redmine core does set priority null.

Sorry, I missed NOT.
Redmine core does NOT set priority null.

#4 Updated by Toshi MARUYAMA 11 months ago

  • Subject changed from Close issue causes Internal Server Error under certain conditions to Issue closing causes error if issue priority default is not defined and issue priority caluculated by sub issues
  • Status changed from Closed to Confirmed
  • Target version set to 3.4.0
  • Resolution deleted (Invalid)

#5 Updated by Toshi MARUYAMA 11 months ago

  • Subject changed from Issue closing causes error if issue priority default is not defined and issue priority caluculated by sub issues to Issue closing causes error if issue priority default is not defined and issue priority is caluculated by sub issues

#6 Updated by Pavel Potcheptsov 11 months ago

If redmine doesn't set NULL for priority and there are no plugins installed and there are no local modifications how can I track down where is problem comes from?
This is only occurs for subtasks.

# svn info
Path: .
Working Copy Root Path: /var/www/rm330
URL: https://svn.redmine.org/redmine/branches/3.3-stable
Relative URL: ^/branches/3.3-stable
Repository Root: https://svn.redmine.org/redmine
Repository UUID: e93f8b46-1217-0410-a6f0-8f06a7374b81
Revision: 15732
Node Kind: directory
Schedule: normal
Last Changed Author: marutosijp
Last Changed Rev: 15722
Last Changed Date: 2016-07-20 08:35:54 +0300 (Wed, 20 Jul 2016)

# svn diff
#

#7 Updated by Toshi MARUYAMA 11 months ago

source:tags/3.3.0/app/models/issue.rb#L1529

As I changed subject, issue priority default is not defined.

#8 Updated by Jean-Philippe Lang 11 months ago

  • Subject changed from Issue closing causes error if issue priority default is not defined and issue priority is caluculated by sub issues to Closing all subtasks causes error if default priority is not defined and priority is derived from subtasks
  • Status changed from Confirmed to Resolved
  • Assignee set to Jean-Philippe Lang
  • Target version changed from 3.4.0 to 3.3.1
  • Resolution set to Fixed

Fix committed in r15857, thanks for pointing this out.

#9 Updated by Jean-Philippe Lang 11 months ago

  • Status changed from Resolved to Closed

Also available in: Atom PDF