1

I have a problem. My mailer sends the same e-mail 4 times. I'm pretty sure I only call it once though. What could be the reason?

Running Rails 3.0.7 on Ruby 1.9.2 and Unicorn, if that matters.

Here is the mailer:

class NotificationMailer < ActionMailer::Base
  default :from => "herald@artistsnclients.com"

  def order_new(user, order)
    @user = user
    @order = order
    mail( :to => "#{user.name} <#{user.email}>", :subject => "You have one new order to review (##{order.id})" )
  end
end

What calls the mailer is a callback in the model Notification:

class Notification < ActiveRecord::Base
  attr_accessible :read, :user_id, :happening_type, :happening_id, :happening_status

  enum_attr :happening_status, %w(new approved rejected cancelled payed completed accepted new_post)

  belongs_to :user
  belongs_to :happening, :polymorphic => true

  after_create :send_email

  private

  def send_email
    # Send e-mail here
    if [:new, :approved, :rejected, :cancelled, :payed, :completed, :accepted].include? self.happening_status
      right_mailer = NotificationMailer.method("order_#{self.happening_status}".to_sym)
      right_mailer.call(self.user, self.happening).deliver
    elsif [:new_post].include? self.happening_status
      NotificationMailer.note_new(self.user, self.happening).deliver
    end
  end
end

The Notification object is created from a callback in the Note model:

class Note < ActiveRecord::Base
  ...
  after_create :notify_artist

  private

  def notify_artist
    self.notifications.create :read => false, :happening_status => :new, :user_id => self.artist_id
  end
end

Also, here is the part of the log that belongs to the controller from which the Notification model is created:

Started POST "/notes" for 178.8.127.86 at 2011-07-15 18:03:45 +0000
  Processing by NotesController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"8UhgV74SUZibcrowriqQZAketiALnkpHMhu0bkuZ4VQ=", "note"=>{"content"=>"Okaaay, *will do*", "order_id"=>"1"}, "commit"=>"Reply"}
  [1m[36mUser Load (0.1ms)[0m  [1mSELECT `users`.* FROM `users` WHERE `users`.`id` = 1 LIMIT 1[0m
  [1m[35mSQL (0.1ms)[0m  BEGIN
  [1m[36mSQL (0.5ms)[0m  [1mdescribe `notes`[0m
  [1m[35mAREL (0.3ms)[0m  INSERT INTO `notes` (`user_id`, `order_id`, `content`, `created_at`, `updated_at`) VALUES (1, 1, 'Okaaay, *will do*', '2011-07-15 18:03:45', '2011-07-15 18:03:45')
  [1m[36mOrder Load (0.1ms)[0m  [1mSELECT `orders`.* FROM `orders` WHERE `orders`.`id` = 1 LIMIT 1[0m
  [1m[35mNotification Load (0.5ms)[0m  SELECT `notifications`.* FROM `notifications` WHERE (`notifications`.happening_id = 12 AND `notifications`.happening_type = 'Note') LIMIT 1
  [1m[36mSQL (0.9ms)[0m  [1mdescribe `notifications`[0m
  [1m[35mAREL (0.3ms)[0m  INSERT INTO `notifications` (`read`, `user_id`, `happening_id`, `happening_type`, `created_at`, `updated_at`, `happening_status`) VALUES (0, 2, 12, 'Note', '2011-07-15 18:03:45', '2011-07-15 18:03:45', 'new_post')
  [1m[36mUser Load (0.2ms)[0m  [1mSELECT `users`.* FROM `users` WHERE `users`.`id` = 2 LIMIT 1[0m
  [1m[35mNote Load (0.3ms)[0m  SELECT `notes`.* FROM `notes` WHERE `notes`.`id` = 12 LIMIT 1
Rendered notification_mailer/note_new.html.haml (3.6ms)

Sent mail to [MY E-MAIL] (2362ms)
Date: Fri, 15 Jul 2011 18:03:46 +0000
From: herald@artistsnclients.com
To: Dummy <[MY E-MAIL]>
Message-ID: <4e208102724f_55c11225a4584d7@artistsnclients.mail>
Subject: New message in order #1
Mime-Version: 1.0
Content-Type: text/html;
 charset=UTF-8
Content-Transfer-Encoding: 7bit

<p>Hello Dummy,</p>
<p>There is a new message in your order #1.</p>
<blockquote>
  Okaaay, *will do*
</blockquote>
<hr>
<p>
  With lots and lots of love,
  <br>
  Artists&amp;Clients Staff
</p>
  [1m[36mSQL (564.1ms)[0m  [1mCOMMIT[0m
Redirected to http://dev.artistsnclients.com/orders/1
Completed 302 Found in 3623ms
Gargron
  • 798
  • 6
  • 9
  • The reason is a full moon and three cows in the bushes. I mean show the code and logs first. – fl00r Jul 15 '11 at 18:19
  • Alright, yes, sorry. I was not exactly sure what part of the code to show and was thinking that maybe it is some kind of version incompatibility, since I had it running on another server with Ruby 1.8 and Passenger and it sent only one e-mail, as it should – Gargron Jul 15 '11 at 18:23
  • and now log file where we can see four outgoing emails – fl00r Jul 15 '11 at 18:28
  • I added the excerpt from log/development.log that is corresponding to the controller where it all is triggered from. (Next entry is already a different controller) So yeah, I only see the template being rendered once. Does that mean that it is simply cached for the other 3 e-mails, or does it mean that the buggery happens in the postmark-rails gem? – Gargron Jul 15 '11 at 18:29
  • Ok, here is only one outgoing email not four – fl00r Jul 15 '11 at 18:32
  • Here is a proof that it was 4 that Postmark sent, a screenshot from the Postmark log: http://gyazo.com/faa787fb72126a0f142ecf67809311c2.png I am pretty sure it is not Postmark's direct fault though, I am using them for at least one different project and such a thing never happened and doesn't happen now either – Gargron Jul 15 '11 at 18:37
  • and yes, it looks like the problem is happened in postmark-rails gem – fl00r Jul 15 '11 at 18:54
  • @fl00r Ah! Wait, this is a way too strange coincidence: My server is a Unicorn with 4 worker_processes... 4 e-mails? Could it be..? – Gargron Jul 15 '11 at 20:21
  • It shouldn't, but it can. Try to run 2 workers. – fl00r Jul 15 '11 at 20:24
  • @fl00r Okay no, that wasn't it. Damn. I am not getting any help here either. Maybe I will try and move e-mail sending to an asynchronous queue, and see how _that_ goes. – Gargron Jul 15 '11 at 20:29
  • Only I can imagine problem here is if you are creating 4 notifications so you are sending four emails (if you're using `accepts_nested_attributes_for`). – fl00r Jul 15 '11 at 20:31
  • @fl00r The thing is, I am not using nested_attributes. I posted the code that triggers a new Notification. – Gargron Jul 15 '11 at 20:36

1 Answers1

0

Please try newer version of the gem named 0.9.8, I think we managed to fix that bug:

https://rubygems.org/gems/postmark

Let me know if it helped.

Ilya Sabanin
  • 766
  • 5
  • 9