メールの送信が停止しました - ファイルの終端に到達しました

みなさん、こんにちは。もしこの内容が、同様のエラーについて言及されている他の投稿と重複しているようでしたら、お詫び申し上げます。

過去 4 日間、すべてのメールの送信が停止しており、テストメールの送信も失敗しています。

類似する既存のトピックを閲覧しましたが、私のケースでは(私が認識している限り)変更点はなく、以前は数ヶ月にわたり問題なく動作していたメール機能が突然停止しました。

当社は Digital Ocean でホスティングを行っており、ドロプレットの IP アドレスからメールを中継するように設定された G Suite SMTP リレーを使用しています。

Sidekiq に表示される正確なエラーメッセージは、discourse-doctor から得られるものよりも詳細です。

Jobs::HandledExceptionWrapper: Wrapped EOFError: end of file reached

discourse-doctor は単に以下のように表示します:
UNEXPECTED ERROR: end of file reached

また、以下のコマンドでサーバーへの接続を確認することができました:

telnet smtp-relay.gmail.com 587

数ヶ月前にもメール送信が一時的に停止したことが一度だけありましたが、その際のエラーは覚えていません(その時は Sidekiq から再試行して問題なく処理できました)。

同様の経験をした方、あるいは現在も機能している類似の設定をお持ちの方がいらっしゃいませんか?ご教示いただけますと幸いです。よろしくお願いいたします。

まだ役立つアドバイスはありませんが、私も全く同じ環境(DigitalOcean の droplet、smtp-relay.gmail.com 経由でのメール送信)で、全く同じ EOFErrors に遭遇しました。

Sidekiq は以下を報告しています:

Jobs::HandledExceptionWrapper: Wrapped EOFError: end of file reached

/logs を確認すると、失敗時のトレースバックは表示されますが、すぐに役立つものは何も見当たりません。

情報:

Job exception: end of file reached

バックトレース:

/usr/local/lib/ruby/2.7.0/net/protocol.rb:225:in `rbuf_fill'
/usr/local/lib/ruby/2.7.0/net/protocol.rb:191:in `readuntil'
/usr/local/lib/ruby/2.7.0/net/protocol.rb:201:in `readline'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:944:in `recv_response'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:929:in `block in getok'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:954:in `critical'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:927:in `getok'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:826:in `helo'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:600:in `do_helo'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:554:in `do_start'
/usr/local/lib/ruby/2.7.0/net/smtp.rb:518:in `start'
mail-2.7.1/lib/mail/network/delivery_methods/smtp.rb:109:in `start_smtp_session'
mail-2.7.1/lib/mail/network/delivery_methods/smtp.rb:100:in `deliver!'
mail-2.7.1/lib/mail/message.rb:2159:in `do_delivery'
mail-2.7.1/lib/mail/message.rb:260:in `block in deliver'
actionmailer-6.0.3.3/lib/action_mailer/base.rb:589:in `block in deliver_mail'
activesupport-6.0.3.3/lib/active_support/notifications.rb:180:in `block in instrument'
activesupport-6.0.3.3/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
activesupport-6.0.3.3/lib/active_support/notifications.rb:180:in `instrument'
actionmailer-6.0.3.3/lib/action_mailer/base.rb:587:in `deliver_mail'
mail-2.7.1/lib/mail/message.rb:260:in `deliver'
actionmailer-6.0.3.3/lib/action_mailer/message_delivery.rb:115:in `block in deliver_now'
actionmailer-6.0.3.3/lib/action_mailer/rescuable.rb:17:in `handle_exceptions'
actionmailer-6.0.3.3/lib/action_mailer/message_delivery.rb:114:in `deliver_now'
/var/www/discourse/lib/email/sender.rb:234:in `send'
/var/www/discourse/app/jobs/regular/user_email.rb:70:in `send_user_email'
/var/www/discourse/app/jobs/regular/user_email.rb:25:in `execute'
/var/www/discourse/app/jobs/base.rb:232:in `block (2 levels) in perform'
rails_multisite-2.5.0/lib/rails_multisite/connection_management.rb:76:in `with_connection'
/var/www/discourse/app/jobs/base.rb:221:in `block in perform'
/var/www/discourse/app/jobs/base.rb:217:in `each'
/var/www/discourse/app/jobs/base.rb:217:in `perform'
sidekiq-6.1.2/lib/sidekiq/processor.rb:196:in `execute_job'
sidekiq-6.1.2/lib/sidekiq/processor.rb:164:in `block (2 levels) in process'
sidekiq-6.1.2/lib/sidekiq/middleware/chain.rb:138:in `block in invoke'
/var/www/discourse/lib/sidekiq/pausable.rb:138:in `call'
sidekiq-6.1.2/lib/sidekiq/middleware/chain.rb:140:in `block in invoke'
sidekiq-6.1.2/lib/sidekiq/middleware/chain.rb:143:in `invoke'
sidekiq-6.1.2/lib/sidekiq/processor.rb:163:in `block in process'
sidekiq-6.1.2/lib/sidekiq/processor.rb:136:in `block (6 levels) in dispatch'
sidekiq-6.1.2/lib/sidekiq/job_retry.rb:111:in `local'
sidekiq-6.1.2/lib/sidekiq/processor.rb:135:in `block (5 levels) in dispatch'
sidekiq-6.1.2/lib/sidekiq.rb:38:in `block in <module:Sidekiq>'
sidekiq-6.1.2/lib/sidekiq/processor.rb:131:in `block (4 levels) in dispatch'
sidekiq-6.1.2/lib/sidekiq/processor.rb:257:in `stats'
sidekiq-6.1.2/lib/sidekiq/processor.rb:126:in `block (3 levels) in dispatch'
sidekiq-6.1.2/lib/sidekiq/job_logger.rb:13:in `call'
sidekiq-6.1.2/lib/sidekiq/processor.rb:125:in `block (2 levels) in dispatch'
sidekiq-6.1.2/lib/sidekiq/job_retry.rb:78:in `global'
sidekiq-6.1.2/lib/sidekiq/processor.rb:124:in `block in dispatch'
sidekiq-6.1.2/lib/sidekiq/logger.rb:10:in `with'
sidekiq-6.1.2/lib/sidekiq/job_logger.rb:33:in `prepare'
sidekiq-6.1.2/lib/sidekiq/processor.rb:123:in `dispatch'
sidekiq-6.1.2/lib/sidekiq/processor.rb:162:in `process'
sidekiq-6.1.2/lib/sidekiq/processor.rb:78:in `process_one'
sidekiq-6.1.2/lib/sidekiq/processor.rb:68:in `run'
sidekiq-6.1.2/lib/sidekiq/util.rb:15:in `watchdog'
sidekiq-6.1.2/lib/sidekiq/util.rb:24:in `block in safe_thread'

環境情報:

hostname	conversation-app
process_id	736
application_version	e6bbe9b5df4d86fe711aa8b1d886489d30875633
current_db	default
current_hostname	conversation.sevarg.net
job	Jobs::UserEmail
problem_db	default
time	12:42 pm
opts	
type	digest
user_id	30
current_site_id	default

discourse-doctor も同様の一般的な出力を返します:

==================== MAIL TEST ====================
For a robust test, get an address from http://www.mail-tester.com/
Or just send a test message to yourself.
Email address for mail test? ('n' to skip) [[my email]]: 
Sending mail to [my email]. . . 
Testing sending to [my email] using smtp-relay.gmail.com:587.
======================================== ERROR ========================================
                                    UNEXPECTED ERROR

end of file reached

====================================== SOLUTION =======================================
This is not a common error. No recommended solution exists!

Please report the exact error message above to https://meta.discourse.org/
(And a solution, if you find one!)
=======================================================================================

また、ポート 587 でリレーへの telnet も可能です(手動でテストメッセージを送信しました…もう 10 年ぶりくらいですが)、最近の履歴でメールに影響を与えるような変更は行った覚えがありません。

新規ユーザーの受け入れなどは完全に立ち往生しており、これはブログのコメント機能としても利用しているため、やや問題です。Google のログを確認しても、特に役立つものは何も見つからず、これ以上トラブルシューティングを続けるアイデアも尽きてしまいました。設定はすべて正しく行われているようですが、なぜか動作しなくなっています。

さて、私の設定があまり一般的でないわけではなく、同じような問題に直面している人が他にもいると知れて安心です。ところで、あなたも問題が約5日前に始まったのでしょうか?もしかすると、私たちのパイプラインで一般的に使われている何かの更新があったのかもしれません。

詳細とバックトレースを共有してくださり、ありがとうございます。私の状況も yours と非常に似ており、エラーも全く同じでした。

telnet から手動でメールを送信する試みはしていませんが、あなたの場合と同様に機能するのではないかと推測しています。

私も同じ状況にあり、当面は新しいユーザーを手動で有効化しています(幸い、毎日数人だけです)。g-suite、Digital Ocean、Discourse の設定には何も変更を加えていないため、実際に何が原因かを特定できないまま何かを変更するのはためらわれます。:confused:

Sidekiq で失敗が初めて本格的に増加したのは 1 月 14 日、つまり 5 日前のことです。それ以前は、無効なメールなどが原因でランダムな失敗が発生していましたが、急激な増加はありませんでした。

Google 管理コンソールでリレー設定を再現し、それら(広く開放されているはずのものも含む)をいじってみましたが、変化はありませんでした。メール送信に使用するポートを変更してみても、やはり変化はありませんでした。

また、5 日前に自分が意識して変更した覚えのある設定はありません。: /

また、DigitalOcean から smtp-relay.gmail.com への接続に関する問題の報告があります。

DigitalOcean 以外の VM(GCE など)から簡単にテストできる方はいますか?

GCE に Discourse をインストールし、自分の認証情報で起動したところ、同じエラーが発生しました(リレーを認証のみに依存するように設定しています)。

======================================== ERROR ========================================
                                    UNEXPECTED ERROR

end of file reached

====================================== SOLUTION =======================================
これは一般的なエラーではありません。推奨される解決策はありません!

上記の正確なエラーメッセージを https://meta.discourse.org/ までご報告ください。
(もし解決策が見つかったら、それも合わせてお知らせください!)
=======================================================================================

リレーに対して IP ベースの認証を設定しても同じ結果になりました。したがって、これは DigitalOcean 固有の問題ではないと思われます。

残念ながら、「Ruby/Rails のメール関連のトラブルシューティング」は私の現在のスキルでは対応しきれません。何かアドバイスはありますか?

これはGmailのSMTPの問題の可能性はありますか?

そのようです。トラブルシューティングのやり方がわからず、これまでの修正の試みもすべて無駄に終わりました。おそらく何かが変更され、Discourse がそれに対応できていないのでしょう。もちろんサポートもありません。

以前はこれらのフォーラムで問題の特定と解決に協力し、良い結果を得てきました。なぜ今回はこれほど静かなのかはわかりません。

Gmail/G Suite の SMTP に問題がある可能性はありますが、@Syonyk 氏は Droplet 上で telnet を使って手動でメールを送信できたと言っています。

G Suite がサイトから送信されたトラフィックをどのように解釈するか、手動で送信されたメッセージと比較してどうなるかは、私には経験が不足しており判断できません。しかし、この状況から推測すると、問題は smtp-relay.gmail へメールを送信しているサービス側にある可能性が高く、リレー自体には問題がないようです。

参考までに、Droplet の IP アドレスは G Suite の管理者設定で明示的に許可されています。また、数ヶ月間、どのサービスにおいても設定の変更を行っていません(現在も変更していません)。

以前、同様の現象が発生したことがありましたが、その際は 1 日(もしかしたら 2 日かもしれませんが、当時はアクセスが少なかったので、それ以上続いていたとしても気づかなかったかもしれません)だけで、比較的すぐに自然に解決しました。

Discourse との SMTP 会話の十分なトレースがない限り、それ以上トラブルシューティングを行う方法がわかりません。また、そのようなトレースを取得する方法もわかりません。

Discourseから月に送信するメールの件数を確認する方法はありますか?別のSMTPリレーを利用する必要がある場合、どれくらいの予算が必要か知りたいです。これは非常にストレスです。

インスタンスの /admin/email/sent 以下にアクセスすると、送信済みのメールを確認し、そこから使用量を推定できます。

ふむ…

サーバーで tcpdump を実行し、discourse-doctor を走らせてみました。そして出力に以下のようなものを見つけました。

...
0x0030:  d10f f8e4 4548 4c4f 206c 6f63 616c 686f  ....EHLO.localho
	0x0040:  7374 0d0a                                st..
...
	0x0030:  de62 f0c3 3432 3120 342e 372e 3020 5472  .b..421.4.7.0.Tr
	0x0040:  7920 6167 6169 6e20 6c61 7465 722c 2063  y.again.later,.c
	0x0050:  6c6f 7369 6e67 2063 6f6e 6e65 6374 696f  losing.connectio
	0x0060:  6e2e 2028 4548 4c4f 2920 6a31 3673 6d34  n..(EHLO).j16sm4
	0x0070:  3831 3932 3976 736d 2e31 202d 2067 736d  81929vsm.1.-.gsm
	0x0080:  7470 0d0a                                tp..

そして重要なのは、telnet でもこのエラーを再現できることです。

root@conversation:~# telnet smtp-relay.gmail.com 587
Trying 74.125.137.28...
Connected to smtp-relay.gmail.com.
Escape character is '^]'.
220 smtp-relay.gmail.com ESMTP ls8sm507258pjb.6 - gsmtp
ehlo localhost.localdomain
421 4.7.0 Try again later, closing connection. (EHLO) ls8sm507258pjb.6 - gsmtp
Connection closed by foreign host.

実際のドメインを送信すると、期待通りのレスポンスが返ってきます。

root@conversation:~# telnet smtp-relay.gmail.com 587
Trying 74.125.137.28...
Connected to smtp-relay.gmail.com.
Escape character is '^]'.
220 smtp-relay.gmail.com ESMTP p10sm668563uaw.3 - gsmtp
ehlo conversation.sevarg.net
250-smtp-relay.gmail.com at your service, [64.227.96.27]
250-SIZE 157286400
250-8BITMIME
250-STARTTLS
250-ENHANCEDSTATUSCODES
250-PIPELINING
250-CHUNKING
250 SMTPUTF8

さて、問題はここからです。Discourse に正しいドメイン文字列を ehlo で送信させるにはどうすればよいのでしょうか?

これが唯一の問題かどうかはわかりませんが、調査を進めるには非常に有望な手がかりに思えます。

なんだか奇妙ですね。これがどこから急に混入したのでしょう?アップデートは行っていないのですが。

それは突然発生したのではなく、もともとそうなっていました。Google が何かを変更しました。

discourse-doctor は、イメージ内であれば /var/www/discourse/lib/tasks/emails.rake 内のテストを呼び出します。

私は以下を変更しました:

Net::SMTP.start(smtp[:address], smtp[:port], 'localhost', smtp[:user_name], smtp[:password], smtp[:authentication])

これを

Net::SMTP.start(smtp[:address], smtp[:port], 'conversation.sevarg.net', smtp[:user_name], smtp[:password], smtp[:authentication])

すると、今度は異なるエラーが発生しました。

======================================== ERROR ========================================
                                    UNEXPECTED ERROR

503 5.5.1 bad sequence of commands e190sm562849qkd.9 - gsmtp


====================================== SOLUTION =======================================
これは一般的なエラーではありません。推奨される解決策は存在しません!

上記のエラーメッセージを正確に https://meta.discourse.org/ へ報告してください
(もし解決策が見つかったら、それも一緒に!)
=======================================================================================

しかし、重要な点は、tcpdump が(まあまあ)正常なフローを示していることです。

22:33:48.393862 IP 64.227.96.27.54610 > 74.125.137.28.587: Flags [P.], seq 1:31, ack 59, win 502, options [nop,nop,TS val 3732187266 ecr 3508646052], length 30
	0x0000:  4500 0052 d4d6 4000 3f06 f237 40e3 601b  E..R..@.?..7@.`.
	0x0010:  4a7d 891c d552 024b 01b4 04a4 94ce dcc7  J}...R.K........
	0x0020:  8018 01f6 74dc 0000 0101 080a de74 a882  ....t........t..
	0x0030:  d121 b0a4 4548 4c4f 2063 6f6e 7665 7273  .!..EHLO.convers
	0x0040:  6174 696f 6e2e 7365 7661 7267 2e6e 6574  ation.sevarg.net
	0x0050:  0d0a                                     ..
22:33:48.408832 IP 74.125.137.28.587 > 64.227.96.27.54610: Flags [.], ack 31, win 256, options [nop,nop,TS val 3508646067 ecr 3732187266], length 0
	0x0000:  4500 0034 5e5d 0000 2b06 bccf 4a7d 891c  E..4^]..+...J}..
	0x0010:  40e3 601b 024b d552 94ce dcc7 01b4 04c2  @.`..K.R........
	0x0020:  8010 0100 a8ae 0000 0101 080a d121 b0b3  .............!..
	0x0030:  de74 a882                                .t..
22:33:48.469560 IP 74.125.137.28.587 > 64.227.96.27.54610: Flags [P.], seq 59:234, ack 31, win 256, options [nop,nop,TS val 3508646128 ecr 3732187266], length 175
	0x0000:  4500 00e3 5e8a 0000 2b06 bbf3 4a7d 891c  E...^...+...J}..
	0x0010:  40e3 601b 024b d552 94ce dcc7 01b4 04c2  @.`..K.R........
	0x0020:  8018 0100 929f 0000 0101 080a d121 b0f0  .............!..
	0x0030:  de74 a882 3235 302d 736d 7470 2d72 656c  .t..250-smtp-rel
	0x0040:  6179 2e67 6d61 696c 2e63 6f6d 2061 7420  ay.gmail.com.at.
	0x0050:  796f 7572 2073 6572 7669 6365 2c20 5b36  your.service,.[6
	0x0060:  342e 3232 372e 3936 2e32 375d 0d0a 3235  4.227.96.27]..25
	0x0070:  302d 5349 5a45 2031 3537 3238 3634 3030  0-SIZE.157286400
	0x0080:  0d0a 3235 302d 3842 4954 4d49 4d45 0d0a  ..250-8BITMIME..
	0x0090:  3235 302d 5354 4152 5454 4c53 0d0a 3235  250-STARTTLS..25
	0x00a0:  302d 454e 4841 4e43 4544 5354 4154 5553  0-ENHANCEDSTATUS
	0x00b0:  434f 4445 530d 0a32 3530 2d50 4950 454c  CODES..250-PIPEL
	0x00c0:  494e 494e 470d 0a32 3530 2d43 4855 4e4b  INING..250-CHUNK
	0x00d0:  494e 470d 0a32 3530 2053 4d54 5055 5446  ING..250.SMTPUTF
	0x00e0:  380d 0a                                  8..

つまり、少なくとも「EHLO localhost」または「EHLO localhost.localdomain」を送信することが問題の一部です。

さて、実際に開発者に対して P0 級の重大な問題を報告するには、いったいどうすればよいのでしょうか?

私は確かにフォーラムでこれらの人々を目にしました。私の限られた情報からは、彼らはフォーラムをかなり綿密に監視しているようです。GitHubも候補ですが、リポジトリのイシュー機能が無効になっているようです。

はい。

これは conversation.sevarg.net
からのテストメールです。

メールの配信は複雑です。最初に確認すべき重要な事項をいくつか挙げます:

私はすでに修正を試みましたが、この修正をアップストリームに反映させる方法がわかりません。

cd /var/discourse
./launcher enter app
vim ./vendor/bundle/ruby/2.7.0/gems/mail-2.7.1/lib/mail/network/delivery_methods/smtp.rb

以下のセクションを探してください。

    DEFAULTS = {
      :address              => 'localhost',
      :port                 => 25,
      :domain               => 'localhost.localdomain',
      :user_name            => nil,
      :password             => nil,
      :authentication       => nil,
      :enable_starttls      => nil,
      :enable_starttls_auto => true,
      :openssl_verify_mode  => nil,
      :ssl                  => nil,
      :tls                  => nil,
      :open_timeout         => nil,
      :read_timeout         => nil
    }

domain 関連の行を変更してください。

    DEFAULTS = {
      :address              => 'conversation.sevarg.net',
      :port                 => 25,
      :domain               => 'conversation.sevarg.net',
      :user_name            => nil,
      :password             => nil,
      :authentication       => nil,
      :enable_starttls      => nil,
      :enable_starttls_auto => true,
      :openssl_verify_mode  => nil,
      :ssl                  => nil,
      :tls                  => nil,
      :open_timeout         => nil,
      :read_timeout         => nil
    }

どちらが重要なのかはわかりませんが、両方を変更することで問題が解決しました。もちろん、ご自身のドメインを使用してください。

アプリ環境から退出してください。

./launcher restart app

これでメールを送信できるようになるはずです。

この変更はアップグレード時に失われる可能性があります。

しかし、現在は期待通りにメールの送受信が行えています。

開発者の方々へ? 修正をお願いします?

提出したバグ報告に基づき、以下の手順をお試しください。

DISCOURSE_SMTP_DOMAIN: [あなたのインストールドメイン]

を app.yml(おそらく /var/discourse/containers/app.yml)に追加してください。

その後、アプリを再構築し(cd /var/discourse; ./launcher rebuild app)、メール送信を試みてください。

念のため確認ですが、DISCOURSE_SMTP_DOMAIN は Discourse サーバーのドメインですか、それともメールのドメインですか?

例えば、私のサーバーは community.acescentral.com というサブドメインにあり、メールは admin@acescentral.com から送信されています。この場合、DISCOURSE_SMTP_DOMAIN は上位の acescentral.com ですか、それとも community というサブドメインですか?

この件を執拗に追いかけてくださり、本当にありがとうございます。