6

Heroku環境でmailerをSidekiqで非同期処理したいのです。
キューは入るのですがプロセスが入りません、開発環境ではプロセスも入り非同期処理を行うことが可能です。

ma$ heroku ps
=== web (Free): bin/rails server -p $PORT -e $RAILS_ENV
web.1: up 2015/07/18 17:47:02 (~ 6m ago)

=== worker (Free): bundle exec sidekiq -q carrierwave
worker.1: crashed 2015/07/18 17:46:52 (~ 6m ago)

#config/initializers/sidkiq.rb
Sidekiq.configure_server do |config|
  case Rails.env
    when 'production' then
      config.redis = { url: ENV['REDISCLOUD_URL'], namespace: 'sidekiq' }
    when 'staging' then
      config.redis = { url: 'redis://stg.redis-example.com:6379', namespace: 'sidekiq' }
    else
      config.redis = { url: 'redis://localhost:6379', namespace: 'sidekiq' }
  end
end

Sidekiq.configure_client do |config|
  case Rails.env
    when 'production' then
      config.redis = { url: ENV['REDISCLOUD_URL'], namespace: 'sidekiq' }
    when 'staging' then
      config.redis = { url: 'redis://stg.redis-example.com:6379', namespace: 'sidekiq' }
    else
      config.redis = { url: 'redis://localhost:6379', namespace: 'sidekiq' }
  end
end

#Procfile
worker: bundle exec sidekiq -C config/sidekiq.yml


#sidekiq.yml
:verbose: false

:concurrency:  25
:queues:
  - default
  - mailers
  - carrierwave
:daemon: true


#heroku restart後
#heroku logs --tail
2015-07-19T03:48:03.145504+00:00 heroku[web.1]: State changed from up to starting
2015-07-19T03:48:03.199847+00:00 heroku[worker.1]: State changed from crashed to starting
2015-07-19T03:48:06.146853+00:00 heroku[web.1]: Stopping all processes with SIGTERM
2015-07-19T03:48:06.902735+00:00 app[web.1]: [2015-07-19 03:48:06] FATAL SignalException: SIGTERM
2015-07-19T03:48:06.902740+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:170:in `select'
2015-07-19T03:48:06.902742+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:170:in `block in start'
2015-07-19T03:48:06.902745+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:32:in `start'
2015-07-19T03:48:06.902746+00:00 app[web.1]:    /app/vendor/ruby-2.0.0/lib/ruby/2.0.0/webrick/server.rb:160:in `start'
2015-07-19T03:48:06.902748+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/rack-1.6.4/lib/rack/handler/webrick.rb:34:in `run'
2015-07-19T03:48:06.902749+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/rack-1.6.4/lib/rack/server.rb:286:in `start'
2015-07-19T03:48:06.902750+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.2.0/lib/rails/commands/server.rb:80:in `start'
2015-07-19T03:48:06.902752+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.2.0/lib/rails/commands/commands_tasks.rb:80:in `block in server'
2015-07-19T03:48:06.902754+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.2.0/lib/rails/commands/commands_tasks.rb:75:in `tap'
2015-07-19T03:48:06.902756+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.2.0/lib/rails/commands/commands_tasks.rb:75:in `server'
2015-07-19T03:48:06.902757+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.2.0/lib/rails/commands/commands_tasks.rb:39:in `run_command!'
2015-07-19T03:48:06.902759+00:00 app[web.1]:    /app/vendor/bundle/ruby/2.0.0/gems/railties-4.2.0/lib/rails/commands.rb:17:in `<top (required)>'
2015-07-19T03:48:06.902760+00:00 app[web.1]:    bin/rails:4:in `require'
2015-07-19T03:48:06.902762+00:00 app[web.1]:    bin/rails:4:in `<main>'
2015-07-19T03:48:06.903091+00:00 app[web.1]: [2015-07-19 03:48:06] INFO  going to shutdown ...
2015-07-19T03:48:06.903167+00:00 app[web.1]: [2015-07-19 03:48:06] INFO  WEBrick::HTTPServer#start done.
2015-07-19T03:48:06.903215+00:00 app[web.1]: => Booting WEBrick
2015-07-19T03:48:06.903217+00:00 app[web.1]: => Rails 4.2.0 application starting in production on http://0.0.0.0:10714
2015-07-19T03:48:06.903218+00:00 app[web.1]: => Run `rails server -h` for more startup options
2015-07-19T03:48:06.903220+00:00 app[web.1]: => Ctrl-C to shutdown server
2015-07-19T03:48:06.903251+00:00 app[web.1]: Exiting
2015-07-19T03:48:08.219896+00:00 heroku[web.1]: Process exited with status 143
2015-07-19T03:48:08.348078+00:00 heroku[worker.1]: Starting process with command `bundle exec sidekiq -C config/sidekiq.yml`
2015-07-19T03:48:08.776837+00:00 heroku[web.1]: Starting process with command `bin/rails server -p 18578 -e production`
2015-07-19T03:48:08.989739+00:00 heroku[worker.1]: State changed from starting to up
2015-07-19T03:48:10.819431+00:00 app[worker.1]: You really should set a logfile if you're going to daemonize
2015-07-19T03:48:10.819468+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.4/lib/sidekiq/cli.rb:173:in `daemonize'
2015-07-19T03:48:10.819470+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.4/lib/sidekiq/cli.rb:41:in `parse'
2015-07-19T03:48:10.819471+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.4/bin/sidekiq:7:in `<top (required)>'
2015-07-19T03:48:10.819472+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/bin/sidekiq:23:in `load'
2015-07-19T03:48:10.819474+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/bin/sidekiq:23:in `<main>'
2015-07-19T03:48:11.573789+00:00 heroku[worker.1]: State changed from up to crashed
2015-07-19T03:48:11.560084+00:00 heroku[worker.1]: Process exited with status 1
2015-07-19T03:48:21.789930+00:00 app[web.1]: [2015-07-19 03:48:21] INFO  WEBrick 1.3.1
2015-07-19T03:48:21.794994+00:00 app[web.1]: [2015-07-19 03:48:21] INFO  WEBrick::HTTPServer#start: pid=3 port=18578
2015-07-19T03:48:21.794295+00:00 app[web.1]: [2015-07-19 03:48:21] INFO  ruby 2.0.0 (2015-04-13) [x86_64-linux]
2015-07-19T03:48:21.959680+00:00 heroku[web.1]: State changed from starting to up
3
  • heroku上でworker dynosがONになっていない、もしくは dynos が足りないということはないですか? heroku ps の結果を調べてみてください。そのProcfileを見る限り dynos は 4 以上である必要がありそうです。
    – KoRoN
    2015年7月16日 17:27
  • heroku psを追加しました。問題ないように思えますがどうでしょうか
    – opps
    2015年7月16日 22:41
  • worker.1: crashed となってます。heroku log にクラッシュの詳細が記録されていると推測されますので、調査してみてください。ああredisのほうも redis.1: crashed ってなってますね。redisが動いていないために、sidekiqも動いてないということかもしれません。
    – KoRoN
    2015年7月17日 1:55

2 件の回答 2

2
+50

2015-07-22 22:40 追記 - まとめ

heroku 上ではファイルを作成することができません。
一方 sidekiq はデーモンモードで起動・実行する場合、
ログをファイルに出力する必要があります。
そのため heroku 上では sidekiq をデーモンモードで動かすことはできません。


以下、オリジナルの経緯

Procfile から

redis: bundle exec redis-server /usr/local/etc/redis.conf

の行を削除 or 無効化してから heroku に push してみてください。

ログからは redis-server の起動にポートかぶりで失敗したせいで、他の worker が止められてしまっているように見えます。他の設定状況から考えると、 heroku 上では rediscloud を使うおつもりのようですので、Profile で redis-server を起動する必要は無いはずです。

これだけが原因であると断定はできないのですが、まずは提案まで。問題が続くようであれば、ログを再取得してみてください。


2015-07-18 19:35 追記

ログから worker 用の dynos が有功に設定されていないのではないかと考えました。それにより dynos の制限を超えてしまって SIGTERM が送信されることで止まっているのではないか、と推測しています。

念のため worker 用の dynos を https://dashboard.heroku.com/ で確認してみてください。以下の様な状態であれば、workerは1つだけ実行可能です。(実行されるコマンドは私のアプリのものですので、多少異なると思われます)

worker dynos on(1)

そうではなく、以下のようになっている場合は worker は利用できないはずです。

worker dynos off

その場合、右上のEditを押してプランを変更することで、workerが利用できるようになります。

変更後に $ heroku restart して、再度ログなどを観測してみてください。

14
  • 削除しました。foreman startで14:46:02 clock.1 | started with pid 18115 14:46:02 worker.1 | started with pid 18116 14:46:03 clock.1 | I, [2015-07-17T14:46:03.398240 #18115] INFO -- : Starting clock for 1 events: [ time_limit_item_check.job ] 14:46:03 clock.1 | I, [2015-07-17T14:46:03.398320 #18115] INFO -- : Triggering 'time_limit_item_check.job' 14:46:03 worker.1 | exited with code 0 14:46:03 system | sending SIGTERM to all processes 14:46:03 clock.1 | terminated by SIGTERM エラーは出なくなりましたが、heroku psを確認するとクラッシュしています。foreman startする前はクラッシュしていません
    – opps
    2015年7月17日 5:49
  • heroku 側のログはそれで全部ですか? プロセスが起動するところから、見れると良いのですが… あと foreman start は、ローカルで実行するためのコマンドであって heroku で実行するためのものではないと考えていたのですが、違うのでしょうか? どういう目的で foreman start しているか教えてください。
    – KoRoN
    2015年7月17日 8:04
  • すいません、どういうわけか常に=== worker (Free): bundle exec sidekiq -q default -q mailers worker.1: crashed 2015/07/17 17:20:09 (~ 16s ago) になってしまいます。開発環境でもプロセスが入らない状態になってしまいました。ログも大量に勝手に流れています。。。上記に追加します。
    – opps
    2015年7月17日 8:26
  • foreman は、Procfile を読み込み、複数のプロセスを管理できるツール。 Heroku を動かす際にも用いられている。とqiitaの記事に書いてありました。clock: bundle exec clockwork lib/clock.rbはforemanを使って始動していました。1ヶ月ほど前に動かしたときは。。
    – opps
    2015年7月17日 8:45
  • 開発環境で foreman start が動かなくなったのは、先ほどProcfile からredisのプロセスを消したためです。ローカルで実行する場合にはredisを起動する必要がありますが、herokuで実行する場合はredisccloudを使うため必要ないはずです。なおherokuで実行する場合は普通 foreman start する必要がありません。勝手にやってくれますので。
    – KoRoN
    2015年7月17日 9:05
0

log directoryが存在しないのが原因でcrashしてる様に見えます。先ずはlog directoryをrepositoryに追加してからpushしてみて下さい。

cd your/project/path
mkdir -p log
touch log/.gitkeep
git add log
git commit -m 'Add log dir for sidekiq'
git push
1
  • 試してみましたがNo such file or directory - ./log/sidekiq.logというエラーが出ました。
    – opps
    2015年7月17日 12:58

この質問に回答するには、ログインする必要があります。

求めていた回答ではありませんか? のタグが付いた他の質問を参照する。