1

I recently installed the Sidekiq gem to send emails in a background process in my Rails app. I have yet to get a single email to send however and Stack Overflow searches have left me empty handed so far. I don't have a good grasp of Sidekiq or Redis so part of the problem might be that I don't really know what to search for or how to interpret the error messages. Before installing Sidekiq the emails would send just fine with the .deliver method.

I'm getting an error message "Connection reset by peer" followed by "End of file reached" when it tries to send it again. There's also a warning message that contains 'sysread_nonblock' and mentions the openssl directory.

2015-09-13T01:59:23.751Z 1400 TID-owidkv8b8 WARN: Errno::ECONNRESET: Connection reset by peer
2015-09-13T01:59:23.751Z 1400 TID-owidkv8b8 WARN: .../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/openssl/buffering.rb:182:in `sysread_nonblock'

Here's my code. Its based on Rails 4.2.3 and Ruby 2.2.1.

Gemfile

gem 'redis'
gem 'sidekiq'

Application.rb

config.active_job.queue_adapter = :sidekiq

config.action_mailer.default_url_options = { host: 'localhost', port: 3000 }

config.action_mailer.delivery_method = :smtp

config.action_mailer.smtp_settings = {
  address:         'smtp.office365.com',
  port:            587,
  authentication:  :login,
  user_name:       ENV['office_email'],
  password:        ENV['office_pw'],
  domain:          'example.com',
  enable_starttls_auto: true
}

Question Controller

QuestionMailer.question_email.deliver_later!

Question Mailer

default from: "info@example.com"

def question_email
    mail(to: "example@gmail.com", subject: 'Question Email')
end

When I start my local server, I do the following:

Start Redis Server

redis-server /usr/local/etc/redis.conf

Start Sidekiq

bundle exec sidekiq -q default -q mailers

Start Rails Server (with foreman)

foreman run rails server

Here's my full log:

2015-09-13T01:59:17.861Z 1400 TID-owidkv8b8 ActionMailer::DeliveryJob JID-2fb2df2aac71bb896b05c7f1 INFO: start
2015-09-13T01:59:23.750Z 1400 TID-owidkv8b8 ActionMailer::DeliveryJob JID-2fb2df2aac71bb896b05c7f1 INFO: fail: 5.889 sec
2015-09-13T01:59:23.751Z 1400 TID-owidkv8b8 WARN: {"class"=>"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper", "wrapped"=>"ActionMailer::DeliveryJob", "queue"=>"mailers", "args"=>[{"job_class"=>"ActionMailer::DeliveryJob", "job_id"=>"708d1ee4-7d66-493e-8b9f-0fefa7838262", "queue_name"=>"mailers", "arguments"=>["QuestionMailer", "question_email", "deliver_now!"]}], "retry"=>true, "jid"=>"2fb2df2aac71bb896b05c7f1", "created_at"=>1442109557.85662, "enqueued_at"=>1442109557.8567731, "error_message"=>"Connection reset by peer", "error_class"=>"Errno::ECONNRESET", "failed_at"=>1442109563.749469, "retry_count"=>0}
2015-09-13T01:59:23.751Z 1400 TID-owidkv8b8 WARN: Errno::ECONNRESET: Connection reset by peer
2015-09-13T01:59:23.751Z 1400 TID-owidkv8b8 WARN: .../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/openssl/buffering.rb:182:in `sysread_nonblock'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/openssl/buffering.rb:182:in `read_nonblock'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/protocol.rb:153:in `rbuf_fill'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/protocol.rb:134:in `readuntil'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/protocol.rb:144:in `readline'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:945:in `recv_response'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:931:in `block in getok'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:955:in `critical'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:929:in `getok'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:923:in `quit'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:616:in `do_finish'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:523:in `ensure in start'
.../.rvm/rubies/ruby-2.2.1/lib/ruby/2.2.0/net/smtp.rb:523:in `start'
.../.rvm/gems/ruby-2.2.1/gems/mail-2.6.3/lib/mail/network/delivery_methods/smtp.rb:112:in `deliver!'
.../.rvm/gems/ruby-2.2.1/gems/mail-2.6.3/lib/mail/message.rb:252:in `deliver!'
.../.rvm/gems/ruby-2.2.1/gems/actionmailer-4.2.3/lib/action_mailer/message_delivery.rb:77:in `deliver_now!'
.../.rvm/gems/ruby-2.2.1/gems/actionmailer-4.2.3/lib/action_mailer/delivery_job.rb:10:in `perform'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/execution.rb:32:in `block in perform_now'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:115:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:115:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:553:in `block (2 levels) in compile'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:503:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:503:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:496:in `block (2 levels) in around'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:341:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:341:in `block (2 levels) in simple'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/logging.rb:23:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/logging.rb:23:in `block (4 levels) in <module:Logging>'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/notifications.rb:164:in `block in instrument'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/notifications.rb:164:in `instrument'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/logging.rb:22:in `block (3 levels) in <module:Logging>'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/logging.rb:43:in `block in tag_logger'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/tagged_logging.rb:68:in `block in tagged'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/tagged_logging.rb:26:in `tagged'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/tagged_logging.rb:68:in `tagged'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/logging.rb:43:in `tag_logger'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/logging.rb:19:in `block (2 levels) in <module:Logging>'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:439:in `instance_exec'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:439:in `block in make_lambda'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:340:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:340:in `block in simple'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:495:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:495:in `block in around'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:503:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:503:in `call'
.../.rvm/gems/ruby-2.2.1/gems/activesupport-4.2.3/lib/active_support/callbacks.rb:88:in `run_callbacks'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/execution.rb:31:in `perform_now'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/execution.rb:21:in `execute'
.../.rvm/gems/ruby-2.2.1/gems/activejob-4.2.3/lib/active_job/queue_adapters/sidekiq_adapter.rb:42:in `perform'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/processor.rb:75:in `execute_job'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/server/active_record.rb:6:in `call'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/logging.rb:30:in `with_context'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/server/logging.rb:7:in `call'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/chain.rb:132:in `call'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/middleware/chain.rb:132:in `invoke'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/processor.rb:51:in `block in process'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/processor.rb:98:in `stats'
.../.rvm/gems/ruby-2.2.1/gems/sidekiq-3.5.0/lib/sidekiq/processor.rb:50:in `process'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/calls.rb:28:in `public_send'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/calls.rb:28:in `dispatch'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/call/async.rb:7:in `dispatch'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/cell.rb:50:in `block in dispatch'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/cell.rb:76:in `block in task'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/actor.rb:339:in `block in task'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/task.rb:44:in `block in initialize'
.../.rvm/gems/ruby-2.2.1/gems/celluloid-0.17.1.2/lib/celluloid/task/fibered.rb:14:in `block in create'

Many thanks in advance for any insights that can be provided!

jww
  • 97,681
  • 90
  • 411
  • 885
George B.
  • 21
  • 5
  • Can you provide your config.action_mailer settings? I.e. the ones in development.rb or whatever your environment is. Also, can you deliver the email just by calling .deliver? I've got a feeling your smtp settings are not properly set up – TomD Sep 13 '15 at 15:09
  • If I call .deliver or deliver_now the email gets sent just fine. It's only when I use sidekiq does it have issues. Here are my config.action_mailers settings: config.action_mailer.raise_delivery_errors = false , config.action_mailer.delivery_method = :smtp config.action_mailer.smtp_settings = { address: 'smtp.office365.com', port: 587, authentication: :login, user_name: ENV['office_email'], password: ENV['office_pw'], domain: 'example.com', enable_starttls_auto: true } – George B. Sep 13 '15 at 19:17
  • I've also updated the application.rb section above to make things easier to read. – George B. Sep 13 '15 at 19:23
  • Just shot in the dark but what happens if you call deliver_later without the bang symbol at the end? – TomD Sep 13 '15 at 21:17
  • It still doesn't work. I only added the '!' originally so that it would raise an exception and give me more error messages to work with. – George B. Sep 13 '15 at 23:12

1 Answers1

1

For anyone who runs into a similar problem, I fixed the error by simply adding this line to config/environments/development.rb

config.action_mailer.perform_deliveries = true

This is set to false by default since typically you don't want to actually send emails in development mode. I'm not sure why deliver_now was working even when this was set to false but what can you do...

George B.
  • 21
  • 5