この記事は「Wantedly 新卒 Advent Calendar 2021」の11日目の記事です。
こんにちは。Wantedlyのバックエンドエンジニアの山岸です。1人5記事というノルマなのに2記事目にして悲鳴を上げ始めています。あたたかく見守ってくれると助かります。

今日はRailsのAction Mailerで思いがけないエラーに出会ったのでその話を深ぼっていこうと思います。

ただのログ用だったのに...

プロダクト開発をしているエンジニアならば誰しもプロダクトを通じてメールを送ったことがあると思います。メールはユーザー側からみるとプロダクトにアクセスすることなく受動的に情報を取得することができる最も一般的な媒体の一つです。プロダクト側から見るとユーザーに直接価値を提供することができるお手軽さがありつつ、開封率やクリック率を見てユーザーの反応の良さを測ることもできます。

Wantedlyでもメールをユーザーに価値を与える場として使用することは多々あります。
自分も先日多くのユーザーにメールを送るべく、バッチ処理を書いていました。

書いたコードは以下のようなものです。

users.each do |user|
  mail = TestMailer.suggest_mail(user)
  p mail

  mail.deliver_later
end

TestMailerは簡単に書くとこんな感じです。

# mailers/test_mailer.rb
class TestMailer < ApplicationMailer
  def suggest_mail(user)
    @user = user
    # なにかしらの処理
    mail to: user.email
  end
end


# mailers/application_mailer.rb
class ApplicationMailer << ActionMailer::Base
end

ApplicationMailerはActionMailer::Baseを継承した一般的なものですね。TestMailerはそのApplicationMailerを継承しています。suggest_mailはTestMailerのaction_nameとして定義されていて特に特殊な処理をしているわけではありません。

このコードはある程度多めのユーザーに送ることが対象者を割り出す作業の時点でわかっていました。
そのためメールを送る処理自体がサーバーの負荷にならないようにdeliver_nowではなくdeliver_laterを使って非同期で送信するようにしています。deliver_laterを使えばActiveJobとしてメール送信のジョブがenqueれて、サーバーの処理に余裕があるときに自動で捌いてくれます。
そしてその前に誰にどういうことを送ったのかログに残そうと思って p mail で Mail::Messageオブジェクトを表示させようとしていました。しかし、deliver_later の部分で以下のようなエラーが返ってきてしまいました。

RuntimeError: You've accessed the message before asking to deliver it later,
so you may have made local changes that would be silently lost if we enqueued 
a job to deliver it. Why? Only the mailer method *arguments* are passed with 
the delivery job! Do not access the message in any way if you mean to deliver it 
later. Workarounds: 1. don't touch the message before calling #deliver_later, 
2. only touch the message *within your mailer method*, or 3. use a custom Active 
Job instead of #deliver_later.

いきなり長いエラーメッセージが出てきてびっくりしちゃいますね(とても丁寧とも言えます)。
今回はこのエラーがなぜ起こったのかを見ていこうと思います。

Railsのコードを読んでいく

まず状況を把握するためには、どこでエラーが発生しているのかを特定する必要があります。
タイミングとしては p mailをした後の deliver_laterです。p mail はメールの内容を表示するだけです。deliver_laterは非同期ジョブを登録しています。どうやら非同期に処理するのが絡んでいそうです。

エラー文をしっかり読んでみましょう。

You've accessed the message before asking to deliver it later,
so you may have made local changes that would be silently lost if we enqueued 
a job to deliver it. Why? Only the mailer method *arguments* are passed with 
the delivery job! Do not access the message in any way if you mean to deliver it 
later.

どうやらメールの内容を決定するタイミングが関係ありそうです。今アクセスしたことによる変更が配信の際に失われると書いてあります。だいぶ強い意志で配信する前にメールオブジェクトにアクセスするなと書いてありますね。

Workarounds: 1. don't touch the message before calling #deliver_later, 
2. only touch the message *within your mailer method*, or 3. use a custom Active 
Job instead of #deliver_later.

そしてその後に一時的な解決方法が3つ書かれています。1つめと２つ目はやはりメールのオブジェクトに触れるな、触れるなら適切な場所でやってほしいという旨が書かれています。そして3つ目にdeliver_laterを使うのではなく、別のActiveJobを使えとあります。1つめと２つめから推測するに直前のp mailが関係してそうですね。ためしに p mailを外すことでメール送信は正常に行われました。中身を表示することがメールオブジェクトにアクセスしたことになり、本来非同期ジョブが行われるときに決定される中身が先に作られてしまったことが直接の原因のようです。また、3つめの解決方法にActiveJobを変えたら良いとあるので、これはdeliver_laterの実装のActiveJobの呼び方に問題があることを示しています。試しにdeliver_nowで行ってみると直前で p mailを行っていたとしてもエラーは出ることなく送信できました。ただ、これは大量のメールを送信する今回のバッチ処理ではdeliver_nowで全てのメールを送るのを見届けるのは非現実的でした。

ここまでで、一応バッチ処理は安全に送る解決はしました。p mailをしないようにするだけです。ただ、せっかくなのでなぜこのようなエラーが行われるのか、不思議な仕様になっているのか見てみましょう。問題はdeliver_laterの実装にあります。もちろん、ActionMailerはRailsの実装に含まれるので、rails/rails を見に行きましょう。ActionMailerはrails/actionmailer/以下に実装されています。

lib/action_mailer/message_delivery.rbの必要なところだけ取ってきました。

require "delegate"

module ActionMailer
  class MessageDelivery < Delegator
    def initialize(mailer_class, action, *args) # :nodoc:
      @mailer_class, @action, @args = mailer_class, action, args

      # The mail is only processed if we try to call any methods on it.
      # Typical usage will leave it unloaded and call deliver_later.
      @processed_mailer = nil
      @mail_message = nil
    end

    # Method calls are delegated to the Mail::Message that's ready to deliver.
    def __getobj__ # :nodoc:
      @mail_message ||= processed_mailer.message
    end

    # Was the delegate loaded, causing the mailer action to be processed?
    def processed?
      @processed_mailer || @mail_message
    end

    # Enqueues the email to be delivered through Active Job. When the
    # job runs it will send the email using +deliver_now+.
    #
    #   Notifier.welcome(User.first).deliver_later
    #   Notifier.welcome(User.first).deliver_later(wait: 1.hour)
    #   Notifier.welcome(User.first).deliver_later(wait_until: 10.hours.from_now)
    #   Notifier.welcome(User.first).deliver_later(priority: 10)
    #
    # Options:
    #
    # * <tt>:wait</tt> - Enqueue the email to be delivered with a delay.
    # * <tt>:wait_until</tt> - Enqueue the email to be delivered at (after) a specific date / time.
    # * <tt>:queue</tt> - Enqueue the email on the specified queue.
    # * <tt>:priority</tt> - Enqueues the email with the specified priority
    #
    # By default, the email will be enqueued using <tt>ActionMailer::MailDeliveryJob</tt>. Each
    # <tt>ActionMailer::Base</tt> class can specify the job to use by setting the class variable
    # +delivery_job+.
    #
    #   class AccountRegistrationMailer < ApplicationMailer
    #     self.delivery_job = RegistrationDeliveryJob
    #   end
    def deliver_later(options = {})
      enqueue_delivery :deliver_now, options
    end

    private
      # Returns the processed Mailer instance. We keep this instance
      # on hand so we can delegate exception handling to it.
      def processed_mailer
        @processed_mailer ||= @mailer_class.new.tap do |mailer|
          mailer.process @action, *@args
        end
      end

      def enqueue_delivery(delivery_method, options = {})
        if processed?
          ::Kernel.raise "You've accessed the message before asking to " \
            "deliver it later, so you may have made local changes that would " \
            "be silently lost if we enqueued a job to deliver it. Why? Only " \
            "the mailer method *arguments* are passed with the delivery job! " \
            "Do not access the message in any way if you mean to deliver it " \
            "later. Workarounds: 1. don't touch the message before calling " \
            "#deliver_later, 2. only touch the message *within your mailer " \
            "method*, or 3. use a custom Active Job instead of #deliver_later."
        else
          @mailer_class.delivery_job.set(options).perform_later(
            @mailer_class.name, @action.to_s, delivery_method.to_s, args: @args)
        end
      end
  end
end

deliver_laterはMessageDeliveryクラスに実装されています。その中身ではなにやらenqueue_deliveryを呼び出しています。deliver_laterなのに、deliver_methodとしてdeliver_nowを渡しているのは興味深いですね。

そして呼び先のenqueue_deliveryの中で先程のエラー文を見つけました。processed?がtrueの場合にエラーが発生するようです。falseのときは正常にActiveJobを呼び出しています。どういうときにprocessed?がtrueになるかというと@processed_mailerか@mail_messageが存在したときにtrueになります。ここでの存在したときというのはnilではないときという意味です。MessageDeliveryのコンストラクタを見ると両方をnilで初期化しています。それではいつはnil以外の値が入るのでしょうか。

RubyのDelegatorの仕組み

答えはこのActionMailerが継承するDelegatorの仕組みにあります。Rubyには標準添付ライブラリのメソッドを委譲する機能としてforwardableとdelegateがあります。今回使っているdelegateはRuby初期から標準添付されているもので委譲先を動的に変えることが可能です。上の __getobj__ はその委譲先を定義しています。委譲の詳しい説明はこの記事を見るとよくわかります。

ここまでの話をまとめると、何者かが__getobj__を呼び出して @processed_mailerが定義され、その存在があることによって processed?がtrueとなってあの長いエラーが呼び出されるというものでした。では一体誰が __getobj__を呼び出しているのでしょうか？

この答えにたどり着くためにDelegatorの中身を見てみましょう。今度はruby/rubyを見ます。

ruby/lib/delegate.rb

class Delegator < BasicObject
  # Handles the magic of delegation through \_\_getobj\_\_.
  #
  ruby2_keywords def method_missing(m, *args, &block)
    r = true
    target = self.__getobj__ {r = false}

    if r && target_respond_to?(target, m, false)
      target.__send__(m, *args, &block)
    elsif ::Kernel.method_defined?(m) || ::Kernel.private_method_defined?(m)
      ::Kernel.instance_method(m).bind_call(self, *args, &block)
    else
      super(m, *args, &block)
    end
  end

  # This method must be overridden by subclasses and should return the object
  # method calls are being delegated to.
  #
  def __getobj__
    __raise__ ::NotImplementedError, "need to define `__getobj__'"
  end
end

MessageDeliveryの継承元であるDelegatorクラスは上のようなものになっています。問題の__getobj__を見るとNotImplementedErrorを起こすようになっていますね。その上のコメントで委譲先のobjectを返すようにoverrideすべきと書いてあります。そして、__getobj__はどこから呼ばれるかというとmethod_missingの中で呼ばれています。method_missingは通常メソッドの定義がないときに呼ばれるものですね。しかし、Delegatorではそこに一手間かましています。これは委譲先のオブジェクトがあったとき、かつ委譲先に呼び出すべきメソッドが定義されているときはそちらを呼び出すようにしています。委譲先がないときや委譲先に呼び出すべきメソッドが定義されていないときに初めてNoMethodErrorを起こすのです。委譲の真髄がここにありましたね。

何はともあれ__getobj__はmethod_missingによって呼ばれることがわかりました。MessageDeliveryでは委譲先をprocessed_mailer.messageとしています。このprocessed_mailerは自分で定義したTestMailerが入ってきて、messageはActionMailer::Baseのattr_internalで定義されている@ _messageが呼び出されます。@_messageにはRailsで利用しているMail gemのオブジェクトが入るので、そのMail::Messageオブジェクトに委譲されるということです。つまり、次に解決すべき問題が「Mail::Messageに定義されていて、MessageDeliveryクラスにもDelegatorクラスにも定義されていないメソッド」を見つけることになりました。

さて、最初の問題に戻ると、deliver_laterをする前に p mailをしたのが原因でした。pメソッドは引数のオブジェクトのinspectメソッドを呼び出して表示することで有名ですね。このinspectが「Mail::Messageに定義されていて、MessageDeliveryクラスにもDelegatorクラスにも定義されていないメソッド」であれば原因特定となります。

MessageDeliveryのコードを眺めてもinspectの定義はありません。Delegatorも覗いてみると、なんと最初の部分でinspectをundefしています。

ruby/lib/delegate.rb

　kernel = ::Kernel.dup
  kernel.class_eval do
    alias __raise__ raise
    [:to_s, :inspect, :=~, :!~, :===, :<=>, :hash].each do |m|
      undef_method m
    end
    private_instance_methods.each do |m|
      if /\Ablock_given\?\z|\Aiterator\?\z|\A__.*__\z/ =~ m
        next
      end
      undef_method m
    end
  end
  include kernel

これはハッシュ化や比較をするときに委譲先で行われるようにするためです。つまり、Delegatorのサブクラスのインスタンスに対してinspectを行うとmethod_missingが呼ばれて、委譲先のinspectが呼ばれるようになるのです。今回の場合だとMail::Messageクラスの以下の部分が呼ばれます。

lib/mail/message.rb

module Mail
  class Message
    def inspect
      "#<#{self.class}:#{self.object_id}, Multipart: #{multipart?}, Headers: #{header.field_summary}>"
    end
  end
end

ここで無事p mailをすることで委譲先であるMail::Messageが呼ばれるまでを追うことができました。

余談ですが、methodの定義元を簡単に確かめてみると、以下のようになります。

pry(main)> TestMailer.suggest_mail(user).method(:inspect).owner
=> ActionMailer::MessageDelivery @

つまり、Delegatorによって委譲することで委譲先のメソッドも自分で定義したことにできるようです。Delegatorの奥の深さが伺えますね。

以上でエラーが出た証拠は全てつながったと思います。流れとしては以下のようなものになるはずです。

1. p mailでActionMailer::MessageDelivery#inspectが呼ばれる
2. inspectはMessageDeliveryにもその継承元であるDelegatorにも定義されていないのでmethod_missingが呼ばれる
3. method_missing内で委譲元にアクセスするため__getobj__が呼ばれる
4. MessageDelivery#__getobj__が呼ばれて@processed_mailerがnilでなくなる
5. deliver_latorが呼ばれて MessageDeliveryのprocessed?がtrueとなりエラーが表示される

原因がわかってスッキリしましたね 🎉🎉🎉

まとめ

今回はメールを送るためにひょんなことから出会ったエラーをrailsやrubyの実装を見ながらRubyのDelegatorの仕組みまで深ぼってみました。今回ActionMailerの実装を追っていて、Mail::Messageを作成するところやメール送信のロジックはより複雑そうな雰囲気を感じたのでそこでまたブログを書いても良いなと思いました。みなさんも興味があったら見てみてください！