jfqd / redmine_helpdesk

Lightweight helpdesk plugin for redmine.
MIT License
193 stars 102 forks source link

Replies are not processed #178

Open dvmer opened 8 months ago

dvmer commented 8 months ago

Hi, the problem occurs only when a reply is to be processed. The mail in the inbox is marked as read but stays there. New tickets, on the other hand, are processed without any problems.

I use this command as a trigger: sudo /opt/bitnami/ruby/bin/rake -f /opt/bitnami/redmine/Rakefile --silent redmine:email:receive_imap RAILS_ENV="production" host=xxx port=993 username=xxx password=xxx ssl=true project=ticket folder=INBOX move_on_success=success move_on_failure=failed no_permission_check=1 unknown_user=accept allow_override=all no_account_notice=1 --trace

The output:

** Invoke redmine:email:receive_imap (first_time)
** Invoke environment (first_time)
** Execute environment
** Execute redmine:email:receive_imap
rake aborted!
SystemStackError: stack level too deep
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/collectors/substitute_binds.rb:14:in `<<'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:704:in `visit_Arel_Nodes_SqlLiteral'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/visitor.rb:30:in `visit'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:320:in `visit_Arel_Nodes_Grouping'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/visitor.rb:30:in `visit'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:779:in `block in inject_join'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:777:in `each'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:777:in `each_with_index'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:777:in `inject_join'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:177:in `collect_nodes_for'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:157:in `visit_Arel_Nodes_SelectCore'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/mysql.rb:30:in `visit_Arel_Nodes_SelectCore'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:124:in `block in visit_Arel_Nodes_SelectStatement'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:123:in `each'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:123:in `inject'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:123:in `visit_Arel_Nodes_SelectStatement'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/mysql.rb:25:in `visit_Arel_Nodes_SelectStatement'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/visitor.rb:30:in `visit'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/visitor.rb:11:in `accept'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/arel/visitors/to_sql.rb:18:in `compile'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:37:in `to_sql_and_binds'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/database_statements.rb:64:in `select_all'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/abstract/query_cache.rb:103:in `select_all'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/connection_adapters/mysql/database_statements.rb:12:in `select_all'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/querying.rb:47:in `find_by_sql'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:843:in `block in exec_queries'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:861:in `skip_query_cache_if_necessary'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:828:in `exec_queries'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:631:in `load'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:249:in `records'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation.rb:244:in `to_ary'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:553:in `find_nth_with_limit'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:538:in `find_nth'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activerecord-6.1.7.6/lib/active_record/relation/finder_methods.rb:122:in `first'
/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:122:in `custom_field_value'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:98:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'

### hundreds of "...mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'"

/bitnami/redmine/plugins/redmine_helpdesk/lib/redmine_helpdesk/mail_handler_patch.rb:108:in `receive_issue_reply_with_helpdesk'
/opt/bitnami/redmine/app/models/mail_handler.rb:157:in `dispatch'
/opt/bitnami/redmine/app/models/mail_handler.rb:141:in `receive'
/opt/bitnami/redmine/app/models/mail_handler.rb:51:in `block in receive'
/opt/bitnami/redmine/vendor/bundle/ruby/3.0.0/gems/activesupport-6.1.7.6/lib/active_support/notifications.rb:205:in `instrument'
/opt/bitnami/redmine/app/models/mail_handler.rb:48:in `receive'
/opt/bitnami/redmine/app/models/mail_handler.rb:57:in `safe_receive'
/opt/bitnami/redmine/lib/redmine/imap.rb:41:in `block in check'
/opt/bitnami/redmine/lib/redmine/imap.rb:38:in `each'
/opt/bitnami/redmine/lib/redmine/imap.rb:38:in `check'
/opt/bitnami/redmine/lib/tasks/email.rake:121:in `block (4 levels) in <top (required)>'
/opt/bitnami/redmine/app/models/mailer.rb:648:in `with_synched_deliveries'
/opt/bitnami/redmine/lib/tasks/email.rake:120:in `block (3 levels) in <top (required)>'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `block in execute'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `each'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/task.rb:281:in `execute'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/task.rb:219:in `block in invoke_with_call_chain'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `synchronize'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/task.rb:199:in `invoke_with_call_chain'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/task.rb:188:in `invoke'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:160:in `invoke_task'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block (2 levels) in top_level'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `each'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:116:in `block in top_level'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:125:in `run_with_threads'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:110:in `top_level'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:83:in `block in run'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:186:in `standard_exception_handling'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/lib/rake/application.rb:80:in `run'
/opt/bitnami/ruby/lib/ruby/gems/3.0.0/gems/rake-13.0.6/exe/rake:27:in `<top (required)>'
/opt/bitnami/ruby/bin/rake:25:in `load'
/opt/bitnami/ruby/bin/rake:25:in `<main>'
Tasks: TOP => redmine:email:receive_imap
Environment:
  Redmine version                5.0.6.stable
  Ruby version                   3.0.6-p216 (2023-03-30) [x86_64-linux]
  Rails version                  6.1.7.6
  Environment                    production
  Database adapter               Mysql2
  Mailer queue                   ActiveJob::QueueAdapters::AsyncAdapter
  Mailer delivery                smtp
Redmine settings:
  Redmine theme                  Classic
SCM:
  Git                            2.30.2
  Filesystem                     
Redmine plugins:
  redmine_checklists             3.1.22
  redmine_helpdesk               0.0.20
  redmine_issue_dynamic_edit     0.9.1
  redmine_questions              1.0.4
  redmine_theme_changer          0.6.0
  redmine_wysiwyg_editor         0.32.0
  redmine_x_lightbox2            1.0.0
  redmine_zenedit                2.0.5
  redmineup_tags                 2.0.13

Edit: production.log with debugging enabled

W, [2023-11-08T16:23:00.372356 #8474]  WARN -- : Creating scope :system. Overwriting existing method Enumeration.system.
W, [2023-11-08T16:23:00.469269 #8474]  WARN -- : Creating scope :sorted. Overwriting existing method User.sorted.
D, [2023-11-08T16:23:01.411286 #8474] DEBUG -- : Receiving message 229
D, [2023-11-08T16:23:01.773878 #8474] DEBUG -- :   Setting Load (0.6ms)  SELECT `settings`.* FROM `settings` WHERE `settings`.`name` = 'mail_from' ORDER BY `settings`.`id` DESC LIMIT 1
D, [2023-11-08T16:23:01.807918 #8474] DEBUG -- :   User Load (0.7ms)  SELECT DISTINCT `users`.* FROM `users` INNER JOIN `email_addresses` ON `email_addresses`.`user_id` = `users`.`id` WHERE `users`.`type` = 'User' AND (LOWER(email_addresses.address) IN ('xxx@xxx.xxx')) ORDER BY `users`.`id` ASC LIMIT 1
D, [2023-11-08T16:23:01.877033 #8474] DEBUG -- :   Issue Load (0.3ms)  SELECT `issues`.* FROM `issues` WHERE `issues`.`id` = 741 LIMIT 1
D, [2023-11-08T16:23:01.923246 #8474] DEBUG -- :   Project Load (0.2ms)  SELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 6 LIMIT 1
D, [2023-11-08T16:23:01.949505 #8474] DEBUG -- :   CustomField Load (0.3ms)  SELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`name` = 'reopen-issues-with' LIMIT 1
D, [2023-11-08T16:23:02.009114 #8474] DEBUG -- :   CustomValue Load (2.8ms)  SELECT `custom_values`.* FROM `custom_values` WHERE (customized_id = 6 AND custom_field_id = 26) ORDER BY `custom_values`.`id` ASC LIMIT 1
D, [2023-11-08T16:23:02.023232 #8474] DEBUG -- :   IssueStatus Load (0.3ms)  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 4 LIMIT 1
D, [2023-11-08T16:23:02.030425 #8474] DEBUG -- :   Issue Load (0.2ms)  SELECT `issues`.* FROM `issues` WHERE `issues`.`id` = 741 LIMIT 1
D, [2023-11-08T16:23:02.031603 #8474] DEBUG -- :   Project Load (0.2ms)  SELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 6 LIMIT 1
D, [2023-11-08T16:23:02.032336 #8474] DEBUG -- :   CustomField Load (0.2ms)  SELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`name` = 'reopen-issues-with' LIMIT 1
D, [2023-11-08T16:23:02.033487 #8474] DEBUG -- :   CustomValue Load (0.3ms)  SELECT `custom_values`.* FROM `custom_values` WHERE (customized_id = 6 AND custom_field_id = 26) ORDER BY `custom_values`.`id` ASC LIMIT 1
D, [2023-11-08T16:23:02.034504 #8474] DEBUG -- :   IssueStatus Load (0.2ms)  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 4 LIMIT 1
D, [2023-11-08T16:23:02.035185 #8474] DEBUG -- :   Issue Load (0.2ms)  SELECT `issues`.* FROM `issues` WHERE `issues`.`id` = 741 LIMIT 1
D, [2023-11-08T16:23:02.036278 #8474] DEBUG -- :   Project Load (0.2ms)  SELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 6 LIMIT 1
D, [2023-11-08T16:23:02.036958 #8474] DEBUG -- :   CustomField Load (0.2ms)  SELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`name` = 'reopen-issues-with' LIMIT 1
D, [2023-11-08T16:23:02.037957 #8474] DEBUG -- :   CustomValue Load (0.2ms)  SELECT `custom_values`.* FROM `custom_values` WHERE (customized_id = 6 AND custom_field_id = 26) ORDER BY `custom_values`.`id` ASC LIMIT 1
D, [2023-11-08T16:23:02.038966 #8474] DEBUG -- :   IssueStatus Load (0.2ms)  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 4 LIMIT 1
D, [2023-11-08T16:23:02.039617 #8474] DEBUG -- :   Issue Load (0.2ms)  SELECT `issues`.* FROM `issues` WHERE `issues`.`id` = 741 LIMIT 1
D, [2023-11-08T16:23:02.040688 #8474] DEBUG -- :   Project Load (0.2ms)  SELECT `projects`.* FROM `projects` WHERE `projects`.`id` = 6 LIMIT 1
D, [2023-11-08T16:23:02.041421 #8474] DEBUG -- :   CustomField Load (0.2ms)  SELECT `custom_fields`.* FROM `custom_fields` WHERE `custom_fields`.`name` = 'reopen-issues-with' LIMIT 1
D, [2023-11-08T16:23:02.042427 #8474] DEBUG -- :   CustomValue Load (0.2ms)  SELECT `custom_values`.* FROM `custom_values` WHERE (customized_id = 6 AND custom_field_id = 26) ORDER BY `custom_values`.`id` ASC LIMIT 1
D, [2023-11-08T16:23:02.043429 #8474] DEBUG -- :   IssueStatus Load (0.2ms)  SELECT `issue_statuses`.* FROM `issue_statuses` WHERE `issue_statuses`.`id` = 4 LIMIT 1
...