※ 会社の esa.io に投稿した記事の転載です。

本番環境で DB の値を書き換えるために、rails runner や rails console を使うことがある。bash もあるかもしれない。

$ heroku run rails r scripts/important.rb -a <App Name>
# or
$ heroku run rails c -a <App Name>

heroku run のログは現在の端末だけにしか出力されない。アプリのログには出力されないため、LogDNA や Papertrail などにも記録されない。

現在の端末を閉じてしまうと、ログが消失するため十分注意すること。

回避方法

↓ 以下のような非対話型コマンドであれば、run:detached サブコマンドを使うことで、LogDNA などに送ることが出来る。ただし、現在の端末には出力されない。

・rails runner
・ls

↓ 対話型コマンドは今回の方法は使えない。他の回避方法があるかは不明。

・rails console
・bash

非対話型コマンドのログをアプリのログに出力する

※ 以下、 を immense-shelf-19179 とします。

run:detached サブコマンドと -t オプションを使う。

$ heroku run:detached -t ls -a immense-shelf-19179
Running ls on ⬢ immense-shelf-19179... done, run.7459 (Hobby)
2019-09-18T05:59:42.797129+00:00 heroku[run.7459]: Starting process with command `ls`
2019-09-18T05:59:43.429271+00:00 heroku[run.7459]: State changed from starting to up
2019-09-18T05:59:44.463225+00:00 heroku[run.7459]: State changed from up to complete
2019-09-18T05:59:44.442709+00:00 heroku[run.7459]: Process exited with status 0
2019-09-18T05:59:44.389919+00:00 app[run.7459]: Procfile
2019-09-18T05:59:44.389950+00:00 app[run.7459]: README.md
2019-09-18T05:59:44.389953+00:00 app[run.7459]: app.json
2019-09-18T05:59:44.389955+00:00 app[run.7459]: index.js
(snip)

以下のとおり、run サブコマンドとは出力フォーマットが異なる点には留意する。

$ heroku run ls -a immense-shelf-19179
Running ls on ⬢ immense-shelf-19179... up, run.7702 (Hobby)
Procfile  README.md  app.json  index.js  node_modules  package-lock.json  package.json  public  test.js  views

おまけ

対話型コマンドを run:detached サブコマンドで起動してしまったら

プロンプトが現在の端末に Attach されないため、向こう側で待ち続ける。

↓ よく見ると向こう側で ‘[1] pry(main)>’ が出力されている。

$ heroku run:detached rails c -a immense-shelf-19179
Running rails c on ⬢ immense-shelf-19179... done, run.9514 (Hobby)
Run heroku logs --app immense-shelf-19179 --dyno run.9514 to view the output.

$ heroku logs --app immense-shelf-19179 --dyno run.9514
2019-09-18T06:02:02.544029+00:00 heroku[run.9514]: Starting process with command `rails c`
2019-09-18T06:02:03.329165+00:00 heroku[run.9514]: State changed from starting to up
2019-09-18T06:02:16.615759+00:00 heroku[run.9514]: State changed from up to complete
2019-09-18T06:02:16.557123+00:00 heroku[run.9514]: Process exited with status 0
2019-09-18T06:02:16.213234+00:00 app[run.9514]: Loading staging environment (Rails 5.2.3)
[1] pry(main)>02:16.538739+00:00 app[run.9514]:

今回の場合、run.9514 (One-off) Dyno が待機し続ける。

$ heroku ps -a immense-shelf-19179
=== run: one-off processes (1)
run.9514 (Hobby): up 2019/09/18 15:02:03 +0900 (~ 13s ago): rails c

=== web (Hobby): bundle exec puma -C config/puma.rb (1)
web.1: up 2019/09/18 12:04:41 +0900 (~ 2h ago)

1 時間経つと SIGTERM を受け取り自動終了する。

手動で停止するには ps:kill サブコマンドを使用する。

$ heroku ps:kill run.9514 -a immense-shelf-19179
Stopping run.9514 dyno on ⬢ immense-shelf-19179... done

裏で何が行われているか?

デバッグログを出して、両者を比較すると分かる。

↓ heroku run は、裏で attach_url が発行され、現在の端末に接続されるようだ。

$ DEBUG='*' heroku run ls -a immense-shelf-19179
(snip)
--> {"command":"ls","attach":true,"env":{"TERM":"screen","COLUMNS":165,"LINES":59}}
Running ls on ⬢ immense-shelf-19179... ⢿
<-- 201 Created
  http <-- POST /apps/immense-shelf-19179/dynos
  http {"attach_url":"rendezvous://rendezvous.runtime.heroku.com:5000/e9921dc55fcc6df5d863221874e70f5bef58318a8e785a108f1ff985309c7548","command":"ls","created_at":"2019-09-20T13:01:11Z","id":"0f0bde73-731f-4a52-82df-e84103dc34ab","name":"run.6626","app":{"id":"8b5795a0-98f6-478b-bb13-f53f4ff99e7c","name":"immense-shelf-19179"},"release":{"id":"c8f828c8-942c-40b6-907b-f3e71ff02732","version":3},"size":"Free","state":"starting","type":"run","updated_at":"2019-09-20T13:01:11Z"} +992ms
(snip)

※ rendezvous という URL スキーマを見た感じ、内部的に rendezvous gem を使っているっぽい?(同僚氏談)

↓ heroku run:detached は、attach_url は発行されない。代わりに Logplex 経由で LogDNA 等にログを送るのだと思う。

$ DEBUG='*' heroku run:detached ls -a immense-shelf-19179
(snip)
--> {"command":"ls","attach":false,"env":{"TERM":"screen","COLUMNS":165,"LINES":59}}
Running ls on ⬢ immense-shelf-19179... ⢿
<-- 201 Created
  http <-- POST /apps/immense-shelf-19179/dynos
  http {"attach_url":null,"command":"ls","created_at":"2019-09-20T13:02:22Z","id":"32fddd0d-b8d3-41e6-806e-631cfef1e125","name":"run.6332","app":{"id":"8b5795a0-98f6-478b-bb13-f53f4ff99e7c","name":"immense-shelf-19179"},"release":{"id":"c8f828c8-942c-40b6-907b-f3e71ff02732","version":3},"size":"Free","state":"starting","type":"run","updated_at":"2019-09-20T13:02:22Z"} +1s
(snip)

※ Heroku では Logplex というログルーターが複数の宛先にログを送る。有名な Fluentd もログルーターの一種。

参考情報

One-Off Dynos > Running tasks in background