Amazon Linux2で、systemdを使ってUnicornを起動したい

Question

Rails初心者エンジニアです。
WebアプリのプロトタイプをAWS上にデプロイ・運用していく予定で、本番環境の構築を進めております。

###実現したいこと
サーバー自動復旧の準備として、Amazon Linux2上で、アプリサーバー（Unicorn）の自動起動の設定を行いたい

###実施内容
0. systemdを使ってunicornを起動するユニットファイル（/etc/systemd/system/unicorn.service）を作成し
0. 設定内容を反映 sudo systemctl daemon-reload
0. 確認のため手動でsystemctlで起動 sudo systemctl start unicorn.service

unicorn.serviceファイルの内容

[Unit]
Description=The unicorn process
After=network.target remote-fs.target nss-lookup.target
Before=nginx.service

[Service]
User=myname
WorkingDirectory=/var/www/rails/myapp
SyslogIdentifier=unicorn
Type=simple
Restart=on-failure

Environment=RAILS_ENV=production
Environment=UNICORN_CONF=/var/www/rails/myapp/config/unicorn.conf.rb
Environment=BUNDLE_GEMFILE=/var/www/rails/myapp/Gemfile
EnvironmentFile=/etc/environment

ExecStart=/bin/bash -l -c 'bundle exec unicorn_rails -c ${UNICORN_CONF} -E ${RAILS_ENV} -D'
ExecStop=/usr/bin/kill -QUIT $MAINPID
ExecReload=/usr/bin/kill -USR2 $MAINPID

[Install]
WantedBy=multi-user.target

参考にしたサイト：
Amazon Linux 2 で unicorn を systemd を使って立ち上げる

###発生事象
Unicronが起動せず、ログは以下の通りとなっております。

● unicorn.service - The unicorn process
   Loaded: loaded (/etc/systemd/system/unicorn.service; disabled; vendor preset: disabled)
   Active: failed (Result: start-limit) since 木 2020-11-19 22:03:24 JST; 1h 22min ago
  Process: 29782 ExecStop=/usr/bin/kill -QUIT $MAINPID (code=exited, status=1/FAILURE)
  Process: 29382 ExecStart=/bin/bash -l -c bundle exec unicorn_rails -c ${UNICORN_CONF} -E ${RAILS_ENV} -D (code=exited, status=0/SUCCESS)
 Main PID: 29382 (code=exited, status=0/SUCCESS)

11月 19 22:03:24 xxx.compute.internal systemd[1]: Unit unicorn.service entered failed state.
11月 19 22:03:24 xxx.compute.internal systemd[1]: unicorn.service failed.
11月 19 22:03:24 xxx.compute.internal systemd[1]: unicorn.service holdoff time over, scheduling restart.
11月 19 22:03:24 xxx.compute.internal systemd[1]: start request repeated too quickly for unicorn.service
11月 19 22:03:24 xxx.compute.internal systemd[1]: Failed to start The unicorn process.
11月 19 22:03:24 xxx.compute.internal systemd[1]: Unit unicorn.service entered failed state.
11月 19 22:03:24 xxx.compute.internal systemd[1]: unicorn.service failed.

###質問
ログから、ExecStop=/usr/bin/kill -QUIT $MAINPID (code=exited, status=1/FAILURE)で失敗していると思われますが、原因や対応方法が分からず困っております。
ご支援のほど、よろしくお願いいたします。

※前提として、systemdを使わず、ワーキングディレクトリで直接bundle exec unicorn_rails -c /var/www/rails/myapp/config/unicorn.conf.rb -D -E productionコマンドを入力し、Unicornが起動することは確認済みです。

###試したこと#1
環境変数を使用せず、unicornの再起動は実施しないようunicorn.serviceファイルを以下の通り変更。

[Unit]
Description=The unicorn process
After=network.target remote-fs.target nss-lookup.target
Before=nginx.service

[Service]
User=myname
WorkingDirectory=/var/www/rails/myapp
SyslogIdentifier=unicorn
Type=simple

ExecStart=/bin/bash -l -c 'bundle exec unicorn_rails -c /var/www/rails/myapp/config/unicorn.conf.rb -E production -D'
ExecStop=/usr/bin/kill -QUIT $MAINPID
ExecReload=/usr/bin/kill -USR2 $MAINPID

[Install]
WantedBy=multi-user.target

実行したところ、Unicornは起動せず、ログは以下の通り。

● unicorn.service - The unicorn process
   Loaded: loaded (/etc/systemd/system/unicorn.service; disabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since 金 2020-11-20 11:23:04 JST; 36s ago
  Process: 6590 ExecStop=/usr/bin/kill -QUIT $MAINPID (code=exited, status=1/FAILURE)
  Process: 6190 ExecStart=/bin/bash -l -c bundle exec unicorn_rails -c /var/www/rails/myapp/config/unicorn.conf.rb -E production -D (code=exited, status=0/SUCCESS)
 Main PID: 6190 (code=exited, status=0/SUCCESS)

11月 20 11:23:03 xxx.compute.internal systemd[1]: Started The unicorn process.
11月 20 11:23:03 xxx.compute.internal systemd[1]: Starting The unicorn process...
11月 20 11:23:04 xxx.compute.internal unicorn[6590]: kill: not enough arguments
11月 20 11:23:04 xxx.compute.internal systemd[1]: unicorn.service: control process exited, code=exited status=1
11月 20 11:23:04 xxx.compute.internal systemd[1]: Unit unicorn.service entered failed state.
11月 20 11:23:04 xxx.compute.internal systemd[1]: unicorn.service failed.

unicorn.serviceのジャーナル。

(・・・中略・・・)
11月 20 10:44:15 xxx.compute.internal unicorn[5569]: kill: not enough arguments
11月 20 10:44:17 xxx.compute.internal unicorn[5972]: kill: not enough arguments
11月 20 11:23:04 xxx.compute.internal unicorn[6590]: kill: not enough arguments
11月 25 09:48:42 xxx.compute.internal unicorn[16521]: kill: not enough arguments

###試したこと#2
unicorn.serviceファイルにおいて、依存関係や、ExecStop、 ExecReloadを削除し、ExecStartのみのシンプルな内容で実行。

[Unit]
Description=The unicorn process

[Service]
User=myname
WorkingDirectory=/var/www/rails/myapp
SyslogIdentifier=unicorn
Type=simple

ExecStart=/bin/bash -l -c 'bundle exec unicorn_rails -c /var/www/rails/myapp/config/unicorn.conf.rb -E production -D'

[Install]
WantedBy=multi-user.target

これまでと異なるログを得られたが、依然としてUnicronは起動せず、原因不明。

● unicorn.service - The unicorn process
   Loaded: loaded (/etc/systemd/system/unicorn.service; disabled; vendor preset: disabled)
   Active: inactive (dead)

11月 25 09:48:40 xxx.compute.internal systemd[1]: Started The unicorn process.
11月 25 09:48:40 xxx.compute.internal systemd[1]: Starting The unicorn process...
11月 25 09:48:42 xxx.compute.internal unicorn[16521]: kill: not enough arguments
11月 25 09:48:42 xxx.compute.internal systemd[1]: unicorn.service: control process exited, code=exited status=1
11月 25 09:48:42 xxx.compute.internal systemd[1]: Unit unicorn.service entered failed state.
11月 25 09:48:42 xxx.compute.internal systemd[1]: unicorn.service failed.
11月 25 10:04:26 xxx.compute.internal systemd[1]: Started The unicorn process.
11月 25 10:04:26 xxx.compute.internal systemd[1]: Starting The unicorn process...
11月 25 11:23:00 xxx.compute.internal systemd[1]: Started The unicorn process.
11月 25 11:23:00 xxx.compute.internal systemd[1]: Starting The unicorn process...

unicorn.logの内容は以下の通り。

I, [2020-11-25T09:48:41.677152 #16516]  INFO -- : Refreshing Gem list
I, [2020-11-25T09:48:42.436156 #16516]  INFO -- : unlinking existing socket=/var/www/rails/myapp/tmp/sockets/.unicorn.sock
I, [2020-11-25T09:48:42.436349 #16516]  INFO -- : listening on addr=/var/www/rails/myapp/tmp/sockets/.unicorn.sock fd=9
I, [2020-11-25T09:48:42.469695 #16516]  INFO -- : master process ready
I, [2020-11-25T09:48:42.477058 #16520]  INFO -- : worker=1 ready
I, [2020-11-25T09:48:42.478356 #16519]  INFO -- : worker=0 ready
I, [2020-11-25T09:48:42.583104 #16516]  INFO -- : reaped #<Process::Status: pid 16519 exit 0> worker=0
I, [2020-11-25T09:48:42.583221 #16516]  INFO -- : reaped #<Process::Status: pid 16520 exit 0> worker=1
I, [2020-11-25T09:48:42.583295 #16516]  INFO -- : master complete

###試したこと#3
ExecStartのパスを/bin/bashからワーキングディレクトリ（/var/www/rails/myapp）に変更して実行。

[Unit]
Description=The unicorn process

[Service]
User=myname
WorkingDirectory=/var/www/rails/myapp
SyslogIdentifier=unicorn
Type=simple

ExecStart=/var/www/rails/myapp 'bundle exec unicorn_rails -c /var/www/rails/myapp/config/unicorn.conf.rb -E production -D'

[Install]
WantedBy=multi-user.target

権限エラー発生してしまう。

systemd[19988]: Failed at step EXEC spawning /var/www/rails/myapp: Permission denied

コマンドラインから、同ディレクトリ・同コマンドを入力してUnicornが起動することは確認済みにも関わらず、上記エラーが発生してしまう。
なお、同ディレクトリには実行権限が付与されていることも確認済みであり、エラー発生原因が不明。

drwxrwxr-x 15 myname myname 4096 11月  3 13:12 myapp

Comments

[yu_1985]

Unicornが立ち上がってない状態で実行しましたか？
また、Userがmynameとなっていますが、それは手動でunicornを実行したユーザと一致してますか？

[hentaiman]

前提はコマンド内の変数にENV使ってませんよね
コマンドラインから全く同じ環境変数を使って全く同じコマンドを試してください

[kuroine01690699]

＞yu_1985さん
コメントありがとうございます。
Unicornが立ち上がってない状態で実行しました。また、mynameの部分も、手動で起動した場合のユーザと一致しております。

＞hentaimanさん
前提では環境変数は使っておりません。
ワーキングディレクトリで、コマンドラインから全く同じコマンド`bundle exec unicorn_rails -c ${UNICORN_CONF} -E ${RAILS_ENV} -D`を入力したところ、以下エラーとなりました。
Errno::ENOENT: No such file or directory @ rb_sysopen - -E

なお、環境変数に問題があると仮定して、unicorn.serviceファイルの内容を、環境変数を使わずに、実行してみましたが、発生事象に記載した同じエラーとなってしまいました。

[yu_1985]

少なくとも3つめがうまく行かないのは、/var/www/rails/myapp は実行ファイルではなくディレクトリなので正しい挙動です。

[yu_1985]

起動しようとした時にunicornのログの方にはなにか出てませんか？

[kuroine01690699]

３つ目のエラーは、ディレクトリを指定しているからなのですね。ありがとうございます。

「試したこと#2」の設定に戻して、起動しようとした際のunicornのログを「試したこと#2」に追記しました。
コマンドラインから正常に起動した際のログと同様でした。

他に試した方がよいこと、足りない情報などありましたら、アドバイス頂けますと幸いです。。

[yu_1985]

unicornのログの時間帯が明らかに起動したときのものではないので、systemdを使って起動しようとしたときの時間帯のログをエラーログ含め確認してください。

[kuroine01690699]

systemdで再実行した際のログのため、時間差異が生じてましたが、誤解を招いてしまうため、当該時間のログを貼り直しました。失礼しました。

[yu_1985]

ps aux | grep unicorn
で、現在unicornが動いているかも確認してください。
unicornのエラーログの方は見てないようですが、エラーログも念の為確認してください。

[kuroine01690699]

プロセスは以下のみで、unicornは動いてないとの認識です。
myname 22189 0.0 0.0 119436 916 pts/1 S+ 15:37 0:00 grep --color=auto unicorn

また、unicornのエラーログのファイルは見当たりませんでした。
myapp/logには以下のファイルのみでした。
development.log nginx.error.log unicorn.log
nginx.access.log production.log

[kuroine01690699]

＞yu_1985 さん
詳細分かっておらず恐縮ですが、なんとか自己解決しました！！
お付き合いいただきありがとうございました！！

Answer 1

unicorn.serviceファイルの[Service]で、Type=simpleからType=forkingに変更することで、解決しました！！

詳細な理由は分かっておりませんが、とりあえずunicornは起動しました。

以下、今回の解決にあたり参考にしたサイトです。
stackoverflow
Systemd入門(4) - serviceタイプUnitの設定ファイル