Forums » Help »
Sometimes mail notifications are lost with Net::SMTPServerBusy error
Added by Andrea Valle about 4 years ago
Hello,
I upgraded form Redmine 3.4.6 to Redmine 4.1.1 and sometimes mail notification are lost with Net::SMTPServerBusy error (as reported below).
I never experienced this error before.
I read about #26791, and this redmine forum page but:
- I'm a bit scared to change production Redmine installation as per this documentation
- according to the error I'm not sure this would be solved by adding a separated task queue
I'm using Office365 SMTP sevrer with relatively few mails: less than 10 recipients.
We are now using the "inline" workaround as suggested here
Anyone knows if this could be a Redmine bug or somehow related to SMTP server?
[ActiveJob] [ActionMailer::DeliveryJob] [a68bbd6f-9bbd-4c19-8a95-defcb269356d] Error performing ActionMailer::DeliveryJob (Job ID: a68bbd6f-9bbd-4c19-8a95-defcb269356d) from Async(mailers) in 1439.24ms: Net::SMTPServerBusy (432 4.3.2 STOREDRV.ClientSubmit; sender thread limit exceeded [Hostname=AM6PR06MB5637.eurprd06.prod.outlook.com]
):
C:/Bitnami/redmine-4.1.1-4/ruby/lib/ruby/2.5.0/net/smtp.rb:969:in `check_response'
C:/Bitnami/redmine-4.1.1-4/ruby/lib/ruby/2.5.0/net/smtp.rb:914:in `data'
C:/Bitnami/redmine-4.1.1-4/ruby/lib/ruby/2.5.0/net/smtp.rb:659:in `block in send_message'
C:/Bitnami/redmine-4.1.1-4/ruby/lib/ruby/2.5.0/net/smtp.rb:854:in `rcptto_list'
C:/Bitnami/redmine-4.1.1-4/ruby/lib/ruby/2.5.0/net/smtp.rb:659:in `send_message'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/mail-2.7.1/lib/mail/network/delivery_methods/smtp_connection.rb:54:in `deliver!'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/mail-2.7.1/lib/mail/network/delivery_methods/smtp.rb:101:in `block in deliver!'
C:/Bitnami/redmine-4.1.1-4/ruby/lib/ruby/2.5.0/net/smtp.rb:519:in `start'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/mail-2.7.1/lib/mail/network/delivery_methods/smtp.rb:109:in `start_smtp_session'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/mail-2.7.1/lib/mail/network/delivery_methods/smtp.rb:100:in `deliver!'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/mail-2.7.1/lib/mail/message.rb:2159:in `do_delivery'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/mail-2.7.1/lib/mail/message.rb:260:in `block in deliver'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/actionmailer-5.2.4.2/lib/action_mailer/base.rb:560:in `block in deliver_mail'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/notifications.rb:168:in `block in instrument'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/notifications.rb:168:in `instrument'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/actionmailer-5.2.4.2/lib/action_mailer/base.rb:558:in `deliver_mail'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/app/models/mailer.rb:710:in `deliver_mail'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/mail-2.7.1/lib/mail/message.rb:260:in `deliver'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/roadie-rails-2.1.1/lib/roadie/rails/inline_on_delivery.rb:13:in `deliver'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/actionmailer-5.2.4.2/lib/action_mailer/message_delivery.rb:114:in `block in deliver_now'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/actionmailer-5.2.4.2/lib/action_mailer/rescuable.rb:17:in `handle_exceptions'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/actionmailer-5.2.4.2/lib/action_mailer/message_delivery.rb:113:in `deliver_now'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/actionmailer-5.2.4.2/lib/action_mailer/delivery_job.rb:16:in `perform'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/execution.rb:39:in `block in perform_now'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:109:in `block in run_callbacks'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/i18n-1.6.0/lib/i18n.rb:297:in `with_locale'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/translation.rb:9:in `block (2 levels) in <module:Translation>'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:118:in `instance_exec'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/logging.rb:26:in `block (4 levels) in <module:Logging>'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/notifications.rb:168:in `block in instrument'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/notifications/instrumenter.rb:23:in `instrument'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/notifications.rb:168:in `instrument'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/logging.rb:25:in `block (3 levels) in <module:Logging>'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/logging.rb:46:in `block in tag_logger'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/tagged_logging.rb:71:in `block in tagged'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/tagged_logging.rb:28:in `tagged'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/tagged_logging.rb:71:in `tagged'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/logging.rb:46:in `tag_logger'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/logging.rb:22:in `block (2 levels) in <module:Logging>'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:118:in `instance_exec'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:136:in `run_callbacks'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/execution.rb:38:in `perform_now'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/execution.rb:24:in `block in execute'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:109:in `block in run_callbacks'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/railtie.rb:28:in `block (4 levels) in <class:Railtie>'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/execution_wrapper.rb:87:in `wrap'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/reloader.rb:73:in `block in wrap'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/execution_wrapper.rb:87:in `wrap'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/reloader.rb:72:in `wrap'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/railtie.rb:27:in `block (3 levels) in <class:Railtie>'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:118:in `instance_exec'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:118:in `block in run_callbacks'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activesupport-5.2.4.2/lib/active_support/callbacks.rb:136:in `run_callbacks'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/execution.rb:22:in `execute'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/activejob-5.2.4.2/lib/active_job/queue_adapters/async_adapter.rb:70:in `perform'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:353:in `run_task'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:342:in `block (3 levels) in create_worker'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `loop'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:325:in `block (2 levels) in create_worker'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `catch'
C:/Bitnami/redmine-4.1.1-4/apps/redmine/htdocs/vendor/bundle/ruby/2.5.0/gems/concurrent-ruby-1.1.6/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:324:in `block in create_worker'
It's clear from the log message "sender thread limit exceeded" that:
The service has various limits to prevent abuse and to ensure fair use. An additional limit is being added. Under the new limit, up to three concurrent connections are allowed to send email messages at the same time. If an application tries to send more than three messages at the same time by using multiple connections, each connection will receive the following error message:
432 4.3.2 STOREDRV.ClientSubmit; sender thread limit exceeded
https://docs.microsoft.com/en-us/exchange/troubleshoot/send-emails/smtp-submission-improvements
Thank you for the feedback.
After the upgrade we had a similar issue with another SMTP server so we decided to move to Office365 trying to solve the issue.
That's why we thought the problem was on the Redmine side.
It seems like there is no way to increment this threshold in Office365.
At the moment we have configured Active Job Async adapter to use at maximum 3 threads like this:
config.active_job.queue_adapter = ActiveJob::QueueAdapters::AsyncAdapter.new min_threads: 1, max_threads: 3, idletime: 600.seconds
Do you think that moving to sidekiq or similar could solve the problem? (maybe they have a throttle mechanism)
Thank you.
Sorry I never use Windows for Redmine and on Linux I simply use sendmail delivery method. So that it is up to sendmail to keep mails in a queue and deliver them in case of throttle on mail-server side.
RE: Sometimes mail notifications are lost with Net::SMTPServerBusy error
-
Added by Pavel Potcheptsov about 4 years ago