Project

General

Profile

Actions
Copy link

Defect #37030

closed

Requests fail with "Can't verify CSRF token authenticity" in mail handler

Added by Matthias Hörmann 11 months ago. Updated 6 months ago.

Status:
Closed
Priority:
Normal
Assignee:
Marius BALTEANU
Category:
Email receiving
Target version:
5.0.1
Start date:
Due date:
% Done:

0%

Estimated time:
Resolution:
Fixed
Affected version:
5.0.0

Description

Environment:
  Redmine version                5.0.0.stable.21535
  Ruby version                   2.5.5-p157 (2019-03-15) [x86_64-linux-gnu]
  Rails version                  6.1.5
  Environment                    production
  Database adapter               Mysql2
  Mailer queue                   ActiveJob::QueueAdapters::AsyncAdapter
  Mailer delivery                sendmail
Redmine settings:
  Redmine theme                  Default
SCM:
  Subversion                     1.10.4
  Git                            2.33.1
  Filesystem
Redmine plugins:
  redmine_agile                  1.6.4
  redmine_checklists             3.1.21
  redmine_theme_changer          0.5.0

After updating our Redmine to 5.0.0 incoming mails do not work because rdm-mailhandler.rb Requests appear in production.log with the error

I, [2022-04-25T14:58:39.595827 #24841]  INFO -- : [apache-342-1650891519593965] Started POST "/mail_handler" for 2a01:4f8:1c1c:f222::1 at 2022-04-25 14:58:39 +0200
I, [2022-04-25T14:58:39.596608 #24841]  INFO -- : [apache-342-1650891519593965] Processing by MailHandlerController#index as HTML
I, [2022-04-25T14:58:39.596815 #24841]  INFO -- : [apache-342-1650891519593965]   Parameters: {"key"=>"<removed for security reasons>", "email"=>"<removed for privacy reasons>", "allow_override"=>"project,tracker,category,assigned_to,priority,start_date,due_date", "unknown_user"=>nil, "default_group"=>nil, "no_account_notice"=>nil, "no_notification"=>nil, "no_permission_check"=>nil, "project_from_subaddress"=>nil, "issue"=>{"tracker"=>"Inbox"}}
W, [2022-04-25T14:58:39.596952 #24841]  WARN -- : [apache-342-1650891519593965] Can't verify CSRF token authenticity.
I, [2022-04-25T14:58:39.597158 #24841]  INFO -- : [apache-342-1650891519593965] Completed 422 Unprocessable Entity in 0ms (ActiveRecord: 0.0ms | Allocations: 118)
F, [2022-04-25T14:58:39.598093 #24841] FATAL -- : [apache-342-1650891519593965]
[apache-342-1650891519593965] ActionController::InvalidAuthenticityToken (ActionController::InvalidAuthenticityToken):
[apache-342-1650891519593965]
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal/request_forgery_protection.rb:211:in `handle_unverified_request'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal/request_forgery_protection.rb:243:in `handle_unverified_request'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal/request_forgery_protection.rb:238:in `verify_authenticity_token'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:427:in `block in make_lambda'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'
[apache-342-1650891519593965] actionpack (6.1.5) lib/abstract_controller/callbacks.rb:34:in `block (2 levels) in <module:Callbacks>'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:199:in `block in halting'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:512:in `block in invoke_before'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:512:in `each'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:512:in `invoke_before'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:105:in `run_callbacks'
[apache-342-1650891519593965] actionpack (6.1.5) lib/abstract_controller/callbacks.rb:41:in `process_action'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal/rescue.rb:22:in `process_action'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/notifications.rb:203:in `block in instrument'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/notifications.rb:203:in `instrument'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal/instrumentation.rb:33:in `process_action'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal/params_wrapper.rb:249:in `process_action'
[apache-342-1650891519593965] activerecord (6.1.5) lib/active_record/railties/controller_runtime.rb:27:in `process_action'
[apache-342-1650891519593965] actionpack (6.1.5) lib/abstract_controller/base.rb:165:in `process'
[apache-342-1650891519593965] actionview (6.1.5) lib/action_view/rendering.rb:39:in `process'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal.rb:190:in `dispatch'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_controller/metal.rb:254:in `dispatch'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/routing/route_set.rb:33:in `serve'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/journey/router.rb:50:in `block in serve'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/journey/router.rb:32:in `each'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/journey/router.rb:32:in `serve'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/routing/route_set.rb:842:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/tempfile_reaper.rb:15:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/etag.rb:27:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/conditional_get.rb:40:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/head.rb:12:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/http/permissions_policy.rb:22:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/http/content_security_policy.rb:19:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/session/abstract/id.rb:266:in `context'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/session/abstract/id.rb:260:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/cookies.rb:689:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/callbacks.rb:98:in `run_callbacks'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/callbacks.rb:26:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
[apache-342-1650891519593965] railties (6.1.5) lib/rails/rack/logger.rb:37:in `call_app'
[apache-342-1650891519593965] railties (6.1.5) lib/rails/rack/logger.rb:26:in `block in call'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/tagged_logging.rb:99:in `block in tagged'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/tagged_logging.rb:37:in `tagged'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/tagged_logging.rb:99:in `tagged'
[apache-342-1650891519593965] railties (6.1.5) lib/rails/rack/logger.rb:26:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
[apache-342-1650891519593965] request_store (1.5.1) lib/request_store/middleware.rb:19:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/request_id.rb:26:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/method_override.rb:24:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/runtime.rb:22:in `call'
[apache-342-1650891519593965] activesupport (6.1.5) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/executor.rb:14:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/static.rb:24:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/sendfile.rb:110:in `call'
[apache-342-1650891519593965] rack (2.2.3) lib/rack/content_length.rb:17:in `call'
[apache-342-1650891519593965] actionpack (6.1.5) lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
[apache-342-1650891519593965] railties (6.1.5) lib/rails/engine.rb:539:in `call'
[apache-342-1650891519593965] /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:107:in `process_request'
[apache-342-1650891519593965] /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:157:in `accept_and_process_next_request'
[apache-342-1650891519593965] /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
[apache-342-1650891519593965] /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:419:in `block (3 levels) in start_threads'
[apache-342-1650891519593965] /usr/lib/ruby/vendor_ruby/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'

Since https://www.redmine.org/projects/redmine/wiki/redminereceivingemails does not mention anything about this and neither does the script I assume the script was not updated when this requirement was added?

Files

37030.patch (1.12 KB) 37030.patch Go MAEDA, 2022-05-11 17:21

Related issues

Related to Redmine - Patch #36317: Set default protect from forgery trueClosedMarius BALTEANU

Actions
Actions
Copy link
 #1

Updated by Matthias Hörmann 11 months ago

In addition to this rdm-mailhandler.rb also does not seem to fail with a proper exit code in this situation.

Actions
Copy link
 #2

Updated by Matthias Hörmann 11 months ago

It actually fails with exit code 77, there must be another reason then why it wasn't logged in my sieve.log unlike past errors.

Actions
Copy link
 #3

Updated by Matthias Hörmann 11 months ago

As a temporary fix I added

 

  def verify_authenticity_token
  end

  def handle_unverified_request
  end

to MailHandlerController (in app/controllers/mail_handler_controller.rb

This seems to work but I am not sure about the exact implications (I know neither Ruby nor Rails nor the Redmine codebase nor whether CSRF is actually needed in this context).

Actions
Copy link
 #4

Updated by Marius BALTEANU 11 months ago

  • Assignee set to Marius BALTEANU
Actions
Copy link
 #5

Updated by Go MAEDA 11 months ago

It seems to be caused by r21379.

Actions
Copy link
 #6

Updated by Go MAEDA 11 months ago

I think the attached patch fixes the issue.

Actions
Copy link
 #7

Updated by Marius BALTEANU 11 months ago

  • Target version set to 5.0.1
Actions
Copy link
 #8

Updated by Marius BALTEANU 11 months ago

  • Status changed from New to Resolved
  • Resolution set to Fixed

Fix committed, thanks!

Actions
Copy link
 #9

Updated by Go MAEDA 11 months ago

  • Related to Patch #36317: Set default protect from forgery true added
Actions
Copy link
 #10

Updated by Marius BALTEANU 11 months ago

  • Subject changed from rdm-mailhandler.rb Requests fail with "Can't verify CSRF token authenticity" to Requests fail with "Can't verify CSRF token authenticity" in mail handler
  • Status changed from Resolved to Closed
Actions
Copy link
 #11

Updated by Aleksandar Pavic 6 months ago

Same problem is with issue_relations_controller.rb I have fixed it by adding
skip_before_action :verify_authenticity_token

However my Redmine was: 4.1.0

Actions
Copy link

Also available in: Atom PDF