500 internal error(updating, creating, searching issue) - Githubissues

fengyedou commented 9 years ago

Background

Recent days I founded there is 500 Internal error occurs, not each time, but a bit influences the usage, all 500 internal error happens when creating a new issue, updating a issue, search a issue, using code review, issue calendar and such issue related operations.

I think some maybe plug-in bug or plug-in confict.

Plugin add select2 component to redmine https://github.com/Undev/redmine__select2 redmine__select2 1.0.5
RedmineSimple plugin Simplify redmine interface https://github.com/Undev/redmine_simple redmine_simple 1.1.5

my env. ////////////////////////////////////////// Environment: Redmine version 2.3.2.stable Ruby version 1.9.3-p231 (2012-05-25) [i386-mingw32] Rails version 3.2.13 Environment production Database adapter Mysql2

All installed plug-ins:

clipboard_image_paste 1.8 copy_parent_issue_id 1.0.0----issue relevant fields_permissions 1.0.0 localizable 0.3.0----issue relevant progressive_projects_list 1.0.0 redmine_agile 1.3.4 redmine_all_files 0.0.3 redmine_appspace 1.0.3 redmine_banner 0.0.9 redmine_better_gantt_chart 0.9.0 redmine_changelog 0.0.1 redmine_checkbox_wiki 0.0.1 redmine_checklists 3.0.1----issue relevant redmine_close_button 0.0.8----issue relevant redmine_code_review 0.6.3----issue relevant redmineselect2 1.0.5----redmine_simple dependency redmine_simple 1.1.5----issue relevant redmine_tags 2.1.0----issue relevant redmine_custom_reports 0.1.4----issue relevant redmine_daily_scrum 0.0.1 redmine_dashboard 2.3.3 redmine_didyoumean 1.2.0----issue relevant redmine_documents_short 0.3.0 redmine_issue_statistics 0.0.1----issue relevant redmine_issue_templates 0.0.8----issue relevant redmine_user_mentions 1.1.0----issue relevant redmine_knowledgebase 3.0.4 redmine_lightbox 0.0.1 redmine_login_audit 0.1.5 redmine_logs 0.0.5 redmine_message_issues 0.1.0 redmine_monitoring_controlling 0.1.1 redmine_my_page_queries 2.1.6 redmine_new_user_notification 0.0.1 redmine_parking_lot_chart 0.0.7 redmine_pdf_export_backports 0.0.1 redmine_plugin_views_revisions 0.0.1 redmine_recent_wiki_pages 0.0.1 redmine_release_notes 1.3.1----issue relevant redmine_reminder 0.3.1 redmine_theme_changer 0.1.0 redmine_time_entry_limit 0.0.2 redmine_touch 0.0.2----issue relevant redmine_wiki_backlinks 0.0.2 redmine_wiki_notes 0.0.2 redmine_wiki_templates 0.1.1 redmine_xls_export 0.2.1.t6----issue relevant redmine_xlsx_format_issue_exporter 0.1.0----issue relevant scrum 0.7.0 sidebar_hide 0.0.6 wiking 1.0.0b

////////////////////////Production.log/////////////////////////

Started GET "/redmine/issues/3502" for xxx at 2014-11-18 08:45:37 +0800 Processing by IssuesController#show as HTML Parameters: {"id"=>"3502"} Current user: xx (id=47) Creating scope :sorted. Overwriting existing method Group.sorted. [1;32mDeface:[0m 1 overrides found for 'issues/show' [1;32mDeface:[0m 'simplify_issue_edit_partial' matched 1 times with 'code:contains("render :partial => 'edit'")' [1;32mDeface: [WARNING][0m No :original defined for 'simplify_issue_edit_partial', you should change its definition to include: :original => 'bf0134266b0492cb1fe9dbe2d9b1b98dc6cfff81' [1;32mDeface:[0m 1 overrides found for 'issues/show' [1;32mDeface:[0m 'simplify_issue_edit_partial' matched 0 times with 'code:contains("render :partial => 'edit'")' Rendered issues/_action_menu.html.erb (30.0ms) Rendered plugins/redmine_close_button/app/views/issues/_close_button.html.erb (0.0ms) Rendered plugins/redmine_code_review/app/views/code_review/_issues_show_details_bottom.html.erb (50.0ms) Rendered plugins/redmine_tags/app/views/issues/_tags.html.erb (30.0ms) Rendered plugins/scrum/app/views/scrum_hooks/issues/_show.html.erb (130.0ms) Rendered plugins/redmine_better_gantt_chart/app/views/issues/_show_estimated_duration.html.erb (30.0ms) Rendered plugins/redmine_checklists/app/views/issues/_checklist.html.erb (20.0ms) Rendered issues/_history.html.erb (10.0ms) Rendered issues/_action_menu.html.erb (0.0ms) [1;32mDeface:[0m 1 overrides found for 'issues/_edit' [1;32mDeface:[0m 'simplify_issue_edit' matched 1 times with 'code:contains("preview_link preview_edit_issue_path(:project_id => @project, :id => @issue), 'issue-form'")' [1;32mDeface: [WARNING][0m No :original defined for 'simplify_issue_edit', you should change its definition to include: :original => '36b7936b54a9ceeacd98731bbd833b207b01bdf5' Rendered plugins/redmine_recent_issues/app/views/recent_issues/_list.html.erb (0.0ms) [1;32mDeface:[0m 1 overrides found for 'issues/_attributes' [1;32mDeface:[0m 'issue_attributes_hidden_assignee' matched 1 times with 'code:contains("f.select :assigned_to_id")' [1;32mDeface: [WARNING][0m No :original defined for 'issue_attributes_hidden_assignee', you should change its definition to include: :original => 'ae005456a5c21a1a12846116dd181da4fa833d51' [1;32mDeface:[0m 1 overrides found for 'issues/_attributes' [1;32mDeface:[0m 'issue_attributes_hidden_assignee' matched 1 times with 'code:contains("f.select :assigned_to_id")' [1;32mDeface: [WARNING][0m No :original defined for 'issue_attributes_hidden_assignee', you should change its definition to include: :original => 'ae005456a5c21a1a12846116dd181da4fa833d51' Rendered issues/_attributes.html.erb (140.4ms) Rendered issues/_form.html.erb (327.6ms) Rendered issues/_edit.html.erb (384.4ms) Rendered issues/show.html.erb within layouts/base (1224.4ms) Completed 500 Internal Server Error in 2042ms

ActionView::Template::Error (undefined method assignee_for_select' for #<#<Class:0x438d140>:0x86eb648>): 17: <% if @issue.safe_attribute? 'assigned_to_id' %> 18: <label><%= l(:field_assigned_to) %></label> 19: <%= f.hidden_field :assigned_to_id, :data => { 20: :initial => assignee_for_select(@issue), 21: :text => @issue.assigned_to.try(:name).to_s } %> 22: <% end %> 23: app/views/issues/_attributes.html.erb:20:inblock in _e87e248df9d25762357c467f1ff65f79' app/helpers/application_helper.rb:955:in labelled_fields_for' app/views/issues/_attributes.html.erb:1:in_e87e248df9d25762357c467f1ff65f79' app/views/issues/_form.html.erb:41:in block in _ab8b0ee41dd1f8135ea91dcb0be35f41' app/helpers/application_helper.rb:955:inlabelled_fields_for' app/views/issues/_form.html.erb:1:in _ab8b0ee41dd1f8135ea91dcb0be35f41' app/views/issues/_edit.html.erb:9:inblock in _9b50e8711be939f2724ea5da88b90e68' app/helpers/application_helper.rb:948:in labelled_form_for' app/views/issues/_edit.html.erb:1:in_9b50e8711be939f2724ea5da88b90e68' app/views/issues/show.html.erb:134:in _19d03af08d9ecdd4cc71c7e60b2d9ba0' app/controllers/issues_controller.rb:119:inblock (2 levels) in show' app/controllers/issues_controller.rb:116:in `show'

Started GET "/redmine/projects/xxx/issues/new" for xx at 2014-11-18 16:09:49 +0800 Processing by IssuesController#new as HTML Parameters: {"project_id"=>"xx"} Current user: xx (id=1) Rendered plugins/redmine_issue_templates/app/views/issue_templates/_issue_select_form.html.erb (0.0ms) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) Rendered plugins/redmine_recent_issues/app/views/recent_issues/_list.html.erb (140.4ms) [1;32mDeface:[0m 1 overrides found for 'issues/_attributes' [1;32mDeface:[0m 'issue_attributes_hidden_assignee' matched 1 times with 'code:contains("f.select :assigned_to_id")' [1;32mDeface: [WARNING][0m No :original defined for 'issue_attributes_hidden_assignee', you should change its definition to include: :original => 'ae005456a5c21a1a12846116dd181da4fa833d51' Rendered issues/_attributes.html.erb (171.6ms) Rendered issues/_form.html.erb (358.8ms) Rendered issues/new.html.erb within layouts/base (358.8ms) Completed 500 Internal Server Error in 468ms

ActionView::Template::Error (undefined method assignee_for_select' for #<#<Class:0x438d140>:0x9782c58>): 17: <% if @issue.safe_attribute? 'assigned_to_id' %> 18: <label><%= l(:field_assigned_to) %></label> 19: <%= f.hidden_field :assigned_to_id, :data => { 20: :initial => assignee_for_select(@issue), 21: :text => @issue.assigned_to.try(:name).to_s } %> 22: <% end %> 23: app/views/issues/_attributes.html.erb:20:inblock in _f7584ca375589a74835923d6a9e4b6e4' app/helpers/application_helper.rb:955:in labelled_fields_for' app/views/issues/_attributes.html.erb:1:in_f7584ca375589a74835923d6a9e4b6e4' app/views/issues/_form.html.erb:41:in block in _8d9fad35d80f24f656fb8f731ff1be6f' app/helpers/application_helper.rb:955:inlabelled_fields_for' app/views/issues/_form.html.erb:1:in _8d9fad35d80f24f656fb8f731ff1be6f' app/views/issues/new.html.erb:11:inblock in _84912b7b8cf7e94b3957b14da1d8d87c' app/helpers/application_helper.rb:948:in labelled_form_for' app/views/issues/new.html.erb:5:in_84912b7b8cf7e94b3957b14da1d8d87c'

Started POST "/redmine/projects/xxx/issues/update_form.js" for xxx at 2014-11-18 16:10:16 +0800 Processing by IssuesController#update_form as JS Parameters: {"utf8"=>"✓", "authenticity_token"=>"Tj56ilqzaXSOhXL67kP+55j5KSz2MrD/CoEeobBbsmA=", "issue"=>{"is_private"=>"0", "tracker_id"=>"8", "subject"=>"", "description"=>"", "status_id"=>"1", "priority_id"=>"2", "assigned_to_id"=>"", "category_id"=>"", "fixed_version_id"=>"", "parent_issue_id"=>"", "start_date"=>"2014-11-18", "due_date"=>"", "estimated_hours"=>"", "custom_field_values"=>{"4"=>"", "5"=>"", "9"=>"", "12"=>"", "18"=>"", "20"=>"", "23"=>[""], "25"=>"", "30"=>"", "35"=>""}, "tag_list"=>"", "sprint_id"=>"2", "pending_effort"=>"", "checklists_attributes"=>{"0"=>{"is_done"=>"0", "subject"=>"", "_destroy"=>"false", "position"=>"1", "id"=>""}}, "select2_watcher_user_ids"=>""}, "issue_template"=>"", "project_id"=>"xx"} Current user: xxx (id=1) Rendered plugins/redmine_issue_templates/app/views/issue_templates/_issue_select_form.html.erb (10.0ms) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) DEPRECATION WARNING: #watcher_tag is deprecated and will be removed in Redmine 3.0. Use #watcher_link instead. (called from watcher_tag at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/app/helpers/watchers_helper.rb:23) Rendered plugins/redmine_recent_issues/app/views/recent_issues/_list.html.erb (140.0ms) [1;32mDeface:[0m 1 overrides found for 'issues/_attributes' [1;32mDeface:[0m 'issue_attributes_hidden_assignee' matched 1 times with 'code:contains("f.select :assigned_to_id")' [1;32mDeface: [WARNING][0m No :original defined for 'issue_attributes_hidden_assignee', you should change its definition to include: :original => 'ae005456a5c21a1a12846116dd181da4fa833d51' Rendered issues/_attributes.html.erb (220.0ms) Rendered issues/_form.html.erb (390.0ms) Rendered plugins/redmine_simple/app/views/issues/_update_form_replacement.js.erb (390.0ms) Rendered plugins/redmine_simple/app/views/issues/update_form.js.erb (390.0ms) Completed 500 Internal Server Error in 590ms

ActionView::Template::Error (undefined method assignee_for_select' for #<#<Class:0x438d140>:0xad188f8>): 17: <% if @issue.safe_attribute? 'assigned_to_id' %> 18: <label><%= l(:field_assigned_to) %></label> 19: <%= f.hidden_field :assigned_to_id, :data => { 20: :initial => assignee_for_select(@issue), 21: :text => @issue.assigned_to.try(:name).to_s } %> 22: <% end %> 23: app/views/issues/_attributes.html.erb:20:inblock in _0d0dc56107ad742404cfb4ddb44798f2' app/helpers/application_helper.rb:955:in labelled_fields_for' app/views/issues/_attributes.html.erb:1:in_0d0dc56107ad742404cfb4ddb44798f2' app/views/issues/_form.html.erb:41:in block in _f87e692fdd5cb17f489d3abdfb956d90' app/helpers/application_helper.rb:955:inlabelled_fields_for' app/views/issues/_form.html.erb:1:in `_f87e692fdd5cb17f489d3abdfb956d90'

fengyedou commented 9 years ago

By the way, I can use the plug-in, there is a simple UI for issue, but sometimes the error shows, I checked yesterday's log, there are more than 10 times error shown.

So I think there maybe some hiding issues.

Thanks for your work.

nodecarter commented 9 years ago

Hi, @fengyedou

I think deface precompling will solve this problem. https://github.com/spree/deface#production--precompiling

You can try the following workaround:

Disable deface unless we precompiling views. Add the following lines to {REDMINE_ROOT}/config/additional_environment.rb:
```
unless ENV['DEFACE_PRECOMPILING']
 config.deface.enabled = false
end
```

Precompile views. Run the following command from redmine root:

bundle exec rake DEFACE_PRECOMPILING=true RAILS_ENV=production deface:clean deface:precompile

Thanks

fengyedou commented 9 years ago

Hi, thanks for your explain, I download the latested deface from https://github.com/spree/deface and put it into redmine plug-in directory, then add the lines above in additional_environment.rb, and run bundle exec rake...precompile...

there is such message:You specified: rails (= 3.2.13) and rails (~> 3.2.13), I found in deface plug-in gemfile there is rails > 3.2.13, default redmine gemfile sets rails=3.2.13. //////////////////////////

I found the simple plugin has gemfile said deface <1.0.0, but the latestet deface maybe > 1.0.0, so I download the 0.9.1 deface from github, and retest like above, this time there is such message: D:\BitNami\redmine-2.3.2-0\apps\redmine\htdocs>bundle exec rake DEFACE_PRECOMPIL ING=true RAILS_ENV=production deface:clean deface:precompile The source :rubygems is deprecated because HTTP requests are insecure. Please change your source to 'https://rubygems.org' if possible, or 'http://ruby gems.org' if not.

There are no gemspecs at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs.

Both cannot sucessfully precompile.

nodecarter commented 9 years ago

Hi @fengyedou, You should not install spree/deface explicit. This gem dependency already has in redmine_simple Gemfile. To install deface gem you only need to execute bundle install command in your redmine root folder.

fengyedou commented 9 years ago

@nodecarter

I run the precompile as below, and make sure tzinfo is installed, but there is such error.

I download deface and put the files into redmine htocs directory.

D:\BitNami\redmine-2.3.2-0\apps\redmine\htdocs>bundle show tzinfo D:/BitNami/redmine-2.3.2-0/ruby/lib/ruby/gems/1.9.1/gems/tzinfo-1.1.0

D:\BitNami\redmine-2.3.2-0\apps\redmine\htdocs>bundle exec rake DEFACE_PRECOMPIL ING=true RAILS_ENV=production deface:clean deface:precompile The source :rubygems is deprecated because HTTP requests are insecure. Please change your source to 'https://rubygems.org' if possible, or 'http://ruby gems.org' if not. D:/BitNami/redmine-2.3.2-0/ruby/lib/ruby/gems/1.9.1/gems/watchr-0.7/lib/watchr.r b:111: Use RbConfig instead of obsolete and deprecated Config. Polyglot: found more than one candidate for tzinfo: D:/BitNami/redmine-2.3.2-0/r uby/lib/ruby/gems/1.9.1/gems/tzinfo-1.1.0/lib/tzinfo, D:/BitNami/redmine-2.3.2-0 /ruby/lib/ruby/gems/1.9.1/gems/tzinfo-1.1.0/lib/tzinfo. You don't have tzinfo installed in your application. Please add it to your Gemfi le and run bundle install rake aborted! uninitialized constant TZInfo::InvalidTimezoneIdentifier D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs/config/environment.rb:14:in `<top (required)>' Tasks: TOP => deface:precompile => environment (See full trace by running task with --trace)

nodecarter commented 9 years ago

Hi @fengyedou, something wrong with your redmine installation. I think there is nothing to fix in this plugin.

fengyedou commented 9 years ago

@nodecarter

I will test in a new empty installed redmine env. to see if there is such error. If there is, I will let you know, thanks.

Restream / redmine_simple

500 internal error(updating, creating, searching issue) #2

There are no gemspecs at D:/BitNami/redmine-2.3.2-0/apps/redmine/htdocs.