Railsで500 Internal Server Errorが発生してしまい原因がわからずに困っています。

Question

開発環境では問題無かったのですが、デプロイ後に動作確認したところ「500 Internal Server Error」が出てしまいます。logを確認しましたが、ハッキリした原因がわかりません。

production.log

I, [2019-05-20T01:17:54.710837 #28258]  INFO -- : Started PATCH "/admin/registers/2" for 1XX.21XX。XX. at 2019-05-20 01:17:54 +0900
I, [2019-05-20T01:17:54.720274 #28258]  INFO -- : Processing by Admin::RegistersController#update as HTML
I, [2019-05-20T01:17:54.720767 #28258]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"UGfhhs4keV7w・・・・・==", "form"=>{"register"=>{"rg_1"=>"退会", "rg_2"=>"退会", "rg_3"=>"退会", "rg_4"=>"在籍", "rg_5"=>"在籍", "rg_6"=>"在籍", "rg_7"=>"退会", "rg_8"=>"退会", "rg_9"=>"退会", "rg_10"=>"退会", "rg_11"=>"退会", "rg_12"=>"退会"}}, "commit"=>"更新", "host"=>"wonder-gate.com", "id"=>"2"}
I, [2019-05-20T01:17:54.766076 #28258]  INFO -- :   Rendering register_mailer/next_payment.html.erb within layouts/mailer
I, [2019-05-20T01:17:54.769285 #28258]  INFO -- :   Rendered register_mailer/next_payment.html.erb within layouts/mailer (2.7ms)
I, [2019-05-20T01:17:54.769971 #28258]  INFO -- :   Rendering register_mailer/next_payment.text.erb within layouts/mailer
I, [2019-05-20T01:17:54.771125 #28258]  INFO -- :   Rendered register_mailer/next_payment.text.erb within layouts/mailer (0.9ms)
I, [2019-05-20T01:17:56.286496 #28258]  INFO -- : Sent mail to [e-mail] (1510.8ms)
I, [2019-05-20T01:17:56.288662 #28258]  INFO -- :   Rendering errors/internal_server_error.html.erb within layouts/admin
I, [2019-05-20T01:17:56.288966 #28258]  INFO -- :   Rendered errors/internal_server_error.html.erb within layouts/admin (0.1ms)
I, [2019-05-20T01:17:56.292547 #28258]  INFO -- :   Rendered admin/shared/_header.html.erb (0.9ms)
I, [2019-05-20T01:17:56.292958 #28258]  INFO -- :   Rendered shared/_footer.html.erb (0.1ms)
I, [2019-05-20T01:17:56.293465 #28258]  INFO -- : Completed 500 Internal Server Error in 1572ms (Views: 5.7ms | ActiveRecord: 6.7ms)

ためしにコンソールで送信出来るか確認してみました。

> user = Customer.find(2)
emailカラムには送信先のメールアドレスが記載されています。
今回は、自分のアドレスで試しています。

> RegisterMailer.next_payment(user).deliver_now

Net::SMTPFatalError: 555 5.5.2 Syntax error. u38sm41434419pgn.73 - gsmtp

Net::SMTPFatalError: 555 5.5.2 Syntax error. u38sm41434419pgn.73 - gsmtpが発生しました。調べてみるとアドレス関係のエラーっぽいようです。
開発中にはメール送信ができていましたがなぜか、デプロイ後はメールの送信が出来なくなっています。メールの設定は以下のようにしています。

config/environments/production.rb

config.action_mailer.delivery_method = :smtp
  config.action_mailer.raise_delivery_errors = true
  config.action_mailer.smtp_settings = {
    address: 'smtp.gmail.com',
    port: 587,
    user_name: ENV["GMAIL_USERNAME"], #送信元メールアドレス
    password: ENV["GMAIL_PASSWORD"],
    domain: 'smtp.gmail.com',
    authentication: 'plain',
    enable_starttls_auto: true
    }

registers_controller.rb

def update
    @time = Time.zone.now
    @month = @time.month
    if @month == 1
      @last_month = 12
      @next_month = 2
    elsif @month == 12
      @last_month = 11
      @next_month = 1
    else
      @last_month = @time.month - 1
      @next_month = @time.month + 1
    end

    @register_form = Admin::RegisterForm.new(Register.find_by(customer_id: params[:id]))
    @register_form.assign_attributes(params[:form])
    if @register_form.save
      flash.notice = '更新しました。'
      reg = Register.find_by(customer_id: params[:id])
      
      if reg["rg_#{@last_month}"] == "退会"
        if reg["rg_#{@month}"] == "在籍"
          if reg["rg_#{@next_month}"] == "在籍"
            user = Customer.find_by(id: params[:id])
            RegisterMailer.new_payment(user).deliver_now
          end
        end
      else
        if reg["rg_#{@last_month}"] == "在籍"
          if reg["rg_#{@month}"] == "在籍"
            if reg["rg_#{@next_month}"] == "在籍"
              user = Customer.find_by(id: params[:id])
              RegisterMailer.next_payment(user).deliver_now　　 #ここでエラー発生
            elsif reg["rg_#{@month}"] == "在籍"
              user = Customer.find_by(id: params[:id])
              RegisterMailer.payment(user).deliver_now
            end
          end
        end
      end
      
      redirect_to :admin_customers
    else
      flash.now.alert = '入力に誤りがあります。'
      render action: 'edit'
    end
  end
end

app/mailers/register_mailer.rb

def next_payment(user)
    @time = Time.zone.now
    @month = @time.month
    if @month == 1
      @last_month = 12
      @next_month = 2
    elsif @month == 12
      @last_month = 11
      @next_month = 1
    else
      @last_mont = @time.month - 1
      @next_month = @time.month + 1
    end
    
    @user = user
    mail to: user.email,
    subject: "ありがとうございます。"
  end

app/mailers/apprication_mailer.rb

class ApplicationMailer < ActionMailer::Base
  default from: '運営局'
  layout 'mailer'
end

syntax errorなのでどこかが間違っているのだと思います。development.rbとproduction.rbのSMTP設定部分は全て同じにしています。しかし、開発時には送信ができて、VPSでは送信が出来ないということはどこかの設定を変更しないといけないのでしょうがどこを変更すればいいのかわかりません。

どなたか教えていただけないでしょうか？宜しくお願いします。

追記
VPS側のFirewallの設定がおかしいのでしょうか？

firewall-cmd --list-all

public (active)
  target: default
  icmp-block-inversion: no
  interfaces: eth0
  sources: 
  services: dhcpv6-client ssh http https smtp
  ports: XXX/tcp XX/tcp XXXXX/tcp
  protocols: 
  masquerade: no
  forward-ports: 
  source-ports: 
  icmp-blocks: 
  rich rules: 

smtpはありますが、そのポートはTCP25だったと思います。しかしfirewallの設定リストを見ると
ports: の中に25/tcpはありませんしproduction.rbで設定したport: 587もありません。しかも
port: 587はsmtpsらしいのでservices:の項目にsmtpsがあってもいいのかと考えますが、どうなんでしょうか？
併せておしえていただけませんでしょうか？
お願いします。

追記（コンソールに出てきたlog?を追記します。）

irb(main):004:0> RegisterMailer.next_payment(user).deliver_now
  Rendering register_mailer/next_payment.html.erb within layouts/mailer
  Rendered register_mailer/next_payment.html.erb within layouts/mailer (2.0ms)
  Rendering register_mailer/next_payment.text.erb within layouts/mailer
  Rendered register_mailer/next_payment.text.erb within layouts/mailer (0.7ms)
RegisterMailer#next_payment: processed outbound mail in 319.0ms
Sent mail to [e-mail] (2289.6ms)
Date: Tue, 21 May 2019 06:12:33 +0900
From: =?UTF-8?B?44Ov44Oz44OA44O844Ky44O844OI6YGL5Za25bGA?=
To: [e-mail]
Message-ID: <[e-mail]>
Subject: =?UTF-8?Q?=E5=88=A9=E7=94=A8=E6=96=99=E9=87=91=E3=81=AE=E3=81=8A=E6=8C=AF=E3=82=8A=E8=BE=BC=E3=81=BF=E3=81=82=E3=82=8A=E3=81=8C=E3=81=A8=E3=81=86=E3=81=94=E3=81=96=E3=81=84=E3=81=BE=E3=81=99=E3=80=82?=
Mime-Version: 1.0
Content-Type: multipart/alternative;
 boundary="--==_mimepart_5ce31841c0ac_7683f897c9c31108038d";
 charset=UTF-8
Content-Transfer-Encoding: 7bit


----==_mimepart_5ce31841c0ac_7683f897c9c31108038d
Content-Type: text/plain;
 charset=UTF-8
Content-Transfer-Encoding: base64

6ZW36LC36YOo5ZKM5bqD44GV44G+DQoNCuOBk+OBruW6puOBr+OAgeaciOmh
jeWIqeeUqOaWmemHkeOBruOBiuaMr+OCiui+vOOBv+OBguOCiuOBjOOBqOOB
huOBlOOBluOBhOOBvuOBl+OBn+OAgg0KNiDmnIjjga7jgZTliKnnlKjjgYzj
gYTjgZ/jgaDjgZHjgovjgojjgYbjgavjgarjgorjgb7jgZfjgZ/jgIINCg0K
44K144Kk44OI44KS44GU5Yip55So44GE44Gf44Gg44GP44Gr44GvDQpodHRw
czovL3dvbmRlci1nYXRlLmNvbQ0K44GL44KJ44Ot44Kw44Kk44Oz44KS6KGM
44Gj44Gm44GP44Gg44GV44GE44CCDQo=

----==_mimepart_5ce31841c0ac_7683f897c9c31108038d
Content-Type: text/html;
 charset=UTF-8
Content-Transfer-Encoding: base64

PCFET0NUWVBFIGh0bWw+DQo8aHRtbD4NCiAgPGhlYWQ+DQogICAgPG1ldGEg
aHR0cC1lcXVpdj0iQ29udGVudC1UeXBlIiBjb250ZW50PSJ0ZXh0L2h0bWw7
IGNoYXJzZXQ9dXRmLTgiIC8+DQogICAgPHN0eWxlPg0KICAgICAgLyogRW1h
aWwgc3R5bGVzIG5lZWQgdG8gYmUgaW5saW5lICovDQogICAgPC9zdHlsZT4N
CiAgPC9oZWFkPg0KDQogIDxib2R5Pg0KICAgIOmVt+iwt+mDqOWSjOW6g+OB
leOBvg0KPGhyIC8+DQo8cD7jgZPjga7luqbjga/jgIHmnIjpoY3liKnnlKjm
lpnph5Hjga7jgYrmjK/jgorovrzjgb/jgYLjgorjgYzjgajjgYbjgZTjgZbj
gYTjgb7jgZfjgZ/jgII8L3A+DQo8cD42IOaciOOBruOBlOWIqeeUqOOBjOOB
hOOBn+OBoOOBkeOCi+OCiOOBhuOBq+OBquOCiuOBvuOBl+OBn+OAgjwvcD4N
Cg0KPFA+44K144Kk44OI44KS44GU5Yip55So44GE44Gf44Gg44GP44Gr44Gv
PGEgaHJlZj0iaHR0cHM6Ly93b25kZXItZ2F0ZS5jb20iPuOBk+OBoeOCiTwv
YT7jgYvjgonjg63jgrDjgqTjg7PjgpLooYzjgaPjgabjgY/jgaDjgZXjgYTj
gII8L1A+DQogIDwvYm9keT4NCjwvaHRtbD4NCg==

----==_mimepart_5ce31841c0ac_7683f897c9c31108038d--

Net::SMTPFatalError: 555 5.5.2 Syntax error. l65sm31373491pfb.7 - gsmtp

Comments

[ockeghem]

さしあたり、firewallは関係ないと思います。500エラーになるということは、firewallは通過していることを意味しますし、firewallがなにか「リクエストを変更するような悪さをする」ことは通常ありません

[set0gut1]

環境変数 GMAIL_USERNAME と GMAIL_PASSWORD はちゃんと値が取れてますか？開発環境で動いていたときとコードが同じなら、そのあたりのような気がします。

[suama]

rails consoleが取れるようなら、ENV["GMAIL_USERNAME"], ENV["GMAIL_PASSWORD"] がコンソール上で正しいものが出力されるかを見てみると良いかと思います。

[koume]

回答ありがとうございます。コンソールで確認したところ
ENV["GMAIL_USERNAME"], ENV["GMAIL_PASSWORD"]とも　.envファイルの内容のものが表示できました。開発環境と同じ値です。

[suama]

user = Customer.find(2) で送信先のユーザのメールアドレスが本番と開発で同じ値が入っていて間違いないとしたら、たとえば from: (送信元）のほうが適切でないメールアドレスになっていませんでしょうか？
productionとdevelopmentで from: が変わるような構成とか。
（default from: '運営局' ではなくて default from: "[e-mail]" とかだとは思いつつ、たぶんそこは記載上そうしているかと思いますが）

（追記です）
From: にメールドレスが入っていないような気がしますが、間違いはないでしょうか？
From: "xxx運営局" <[e-mail]> とか
From: [e-mail]
になるのが正しそうですが、"xxx運営局" といいう名称しか入っていないようです。

[CHERRY]

to: suama さん

From は、 https://tools.ietf.org/html/rfc5322#section-3.4 に書かれているとおり、名前部分は省略できますが、addr-spec ( メールアドレス )は省略できないので、メールアドレスがないとエラーの原因になりそうです。

回答欄に書きませんか？ ＞ suama さん

to: koume さん

Gmail 経由で送信する場合、送信するメールの From アドレスが、 gmail.com 以外の場合は、Gmail に追加して確認済みのメールアドレスしか使えませんので、From で使っているアドレスがGmail以外の場合は確認済みになっているかを確認してください。

[suama]

CHERRYさん、ありがとうございます！了解しました！

Answer 1

こんにちは。質問者さま、何回か追記、質問をさせていただきました。ありがとうございます！
また、CHERRYさま、誘導してくださってありがとうございます。

回答というほどにはならないかもしれませんが、念のため、From / To: として実際に入ってくる値が、正しいメールアドレス形式になっているかもご確認ください。

From: =?UTF-8?B?44Ov44Oz44OA44O844Ky44O844OI6YGL5Za25bGA?=
To: [e-mail]

の部分は、デコードすると 「xxx運営局」になっていて、[e-mail] や "xxx運営局" [e-mail] になっていないので、そこでエラーになっているかもしれません。

Fromやその他のメールヘッダが環境変数(RAILS_ENV) に応じて調整されるようになっていたら、development環境では正しくメールが送れたのに、本番でNGだとすると、このあたりの値が気になるかなと思います。
通信上のエラーだともっと違うメッセージが出そうな気はします。
CCで連結とか、環境変数で切り替えとかの場合、なにかゴミが入ってるかもしれません。

rails consoleでも確認されているかと思いますが、メール送信は外に出るものなので、慎重に確認するに越したことはないと思います。
上手くいくといいですね。

Comments

[koume]

回答ありがとうございます。
postfixの設定をなにもしていないので、そこが原因かもしれないので設定を見直した後で
試してみることにします。

Answer 2

エラーが

Net::SMTPFatalError: 555 5.5.2 Syntax error. u38sm41434419pgn.73 - gsmtp

ということは、gmail のサーバーまでは通信できていて、 gmail の SMTP サーバーにデータを送信した際に 「250 OK」ではなく、「555 5.5.2 Syntax error」が返ってきたということです。

503, 530, 535 ではないので、おそらく認証は通っていると考えられます。( gmail には、ステータスに関するヘルプがないので参考ですが、SMTP エラー リファレンス - G Suite 管理者ヘルプ 参照。)

「555 5.5.2 Syntax error」の場合は、メールヘッダかメールボディが、 RFC 5322 や RFC 6854 で決められた書式を守っていない可能性が高いです。

原因の可能性としては、たとえば、

• コントロールコードの混入
• メールヘッダには、US-ASCII しか使えないが、日本語等が正しくエンコーディングされていない
• 文字数オーバー

etc...

いろいろあるので、メールの送信のログを取りながらデバッグしてみてください。

Rails でメールのログは、

ActionMailer の送信ログをとりたい
開発中にrailsから送信したメールを確認する

等を参照してください。

Comments

[koume]

いつもご丁寧な回答有り難うございます。
エンコードのことが気になり表示された内容を確認したところ
Sent mail to [e-mail] (1532.8ms)
Date: Mon, 20 May 2019 20:35:58 +0900
From: =?UTF-8?B?44Ov44Oz44OA44O844Ky44O844OI6YGL5Za25bGA?=
To: [e-mail]
Message-ID: <[e-mail]>
Subject: =?UTF-8?Q?=E5=88=A9=E7=94=A8=E6=96=99=E9=87=91=E3=81=AE=E3=81=8A=E6=8C=AF=E3=82=8A=E8=BE=BC=E3=81=BF=E3=81=82=E3=82=8A=E3=81=8C=E3=81=A8=E3=81=86=E3=81=94=E3=81=96=E3=81=84=E3=81=BE=E3=81=99=E3=80=82?=

となっていました。FormとSubjectの部分の先頭に?UTF-8?がありました。これに違和感を感じるのですが、ここはこの表示で問題ないのでしょうか？

[CHERRY]

=?UTF-8?B? は、 BASE64エンコードですね。
=?UTF-8?Q? は、 Qエンコード( Quoted-Printable ) ですね。

どちらも RFC で認められている内容なので、問題はなさそうですねぇ...

[koume]

以下の設定でlogが出るようにしたのですが、logが出ないのには何か原因があるのでしょうか？
config/application.rbにconfig.mail_logger = Logger.new("log/mail_#{Rails.env}.log")を追記。

config/initializers/email_log_observer.rb　を新規に作成。
class EmailLogObserver

def delivered_email(email)
msg = "from: #{email.from.join(',')} to: #{email.to.join(',')} subject: #{email.subject}"
Rails.application.config.mail_logger.debug(msg)
end
end

app/mailers/application_mailer.rbのApplicationMailer宣言後に一行追記
ActionMailer::Base.register_observer(EmailLogObserver.new)

再度、エラーの出る送信メールを実行しました。
mail_production.logは出来ていますが、出力結果は
# Logfile created on 2019-05-20 20:00:05 +0900 by logger.rb/54362の一行だけです。

エラーに関するlogを見たいのですが、logを出力させるのにはどのように設定すればいいのか教えていただけないでしょうか？宜しくお願いいたします。

[koume]

しつこいようで申し訳ございません。
Action Mailerの設定でdevelopment.rbに記載されていてproduction.rbには無いコードがありました。
development.rbには以下の２行が有りproduction.rbにはありませんでした。
config.action_mailer.raise_delivery_errors = false
config.action_mailer.perform_caching = false
このコードの有無は関係あるのでしょうか？

[koume]

コンソールでメール送信を実行したときにでてきた内容を追記させていただきました。
よくわからないのですが最初の----==_mimepart_5ce31841c0ac_7683f897c9c31108038dのところで
htmlファイルを読み込み２回目のところでtext.htmlを読み込み３回目のところでエラーが発生しています。
ということは自分の設定だとRegisterMailerのnext_paymentアクションを呼び
next_payment.html.erbとnext_payment.text.erbの読み込みまでは成功し
アクション内のmail to: user.emailでそのアドレスに送信しようとしてエラーが発生した。
ということなのでしょうか？だとすると間違ったアドレスということなのでしょうか？
見当違いな解釈かもしれませんが、宜しくお願いします。

[koume]

CHERRY様、まだ解決できずにいますが、さくらのVPSのpostfixの設定についてなにも編集していないので
それが影響しているとかあるのでしょうか？
postfixにドメイン名の設定とかhost nameの設定などの記事をつけたので気になっていますが
それが原因なのでしょうか？

[koume]

いつも、詳しい回答ありがとうございます。
postfixの設定を何もしていなかったので、もしかしたらそれが原因かもしれないのでpostfixの
学習をして、改めて実行してみます。

Answer 3

いろいろ試してみましたが、解決に至りませんでした。
もしかしたらpostfixをインストールしっぱなしで設定していないのが原因かもしれないので
設定の学習をして試してみたいと思います。