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: "[email protected]"
def question_email
mail(to: "[email protected]", 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!
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...