Railsから複数行のLinuxコマンドを非同期で実行させる

# Railsから複数行のLinuxコマンドを非同期（バックグラウンド）で実行させる

時間のかかる処理を非同期で実行させる場合に、いろいろはまったのでまとめておきます。

最終ゴール：

**複数行のLinuxコマンド（ShellScript）を非同期で実行させ、
途中でキャンセルもできるようにする**

非同期で実行する仕組みはresqueとかsidekiqとかいくつもありますが、

- 非同期で実行させたいのはRubyのコードではなくLinuxのコマンドだけ
- 定期ジョブで実行させたい（コマンド処理が終わればRubyは終了させたい）

ということもあり、Ruby標準の仕組みで簡単に済まそうと考えました。

ポイントは次の6つです。

- 複数のLinuxコマンドは実行可能ファイルにまとめる
- その実行可能ファイルを非同期（バックグラウンド）で実行させる
- バックグラウンド実行のために標準出力と標準エラーをファイルに落としておく（もしくは/dev/nullにリダイレクト）
- forkしてrailsとは別プロセスで実行させる
- キャンセル用（kill用）にpidを取得しておく
- pidからpgidを取得し、紐づいている子プロセス含めて全てキャンセルする

Linuxコマンド実行は次のページを参考にしました。

[Rubyで外部コマンドを実行して結果を受け取る方法あれこれ](http://qiita.com/tyabe/items/56c9fa81ca89088c5627)

結論を早く見たい人は、 **試行3** あたりから見てもらえると良いと思います。

## 非同期処理させたいLinuxコマンドを準備

まず時間のかかる処理をtest_commandとして作っておきます。

```bash
$ echo "sleep 100000" > ~/bin/test_command
$ chmod +x ~/bin/test_command
```

```:~/bin/test_command
sleep 100000
```

次にRailsにtest_commandを呼び出す部分とキャンセルする部分を作ります。
（本当はpidをmodelやファイルに保存するなどの処理が必要ですが、この記事用にはpidを標準出力に表示させる形にしています）

## 試行1（IO.popenを使う）

最初に試したのはIO.popenです。
pidが簡単に取れそうだったからです。

```rb:lib/job_task.rb
class JobTask
  class << self
    def execute
      execute_job "test_command > test.log >2&1 &"
    end

    def cancel(pid)
      IO.popen("kill -TERM #{pid}")
      p "canceled!"
    end

    private

    def execute_job(command)
      begin
        IO.popen("#{command}"){|pipe| p pipe.pid}
      rescue => e
        Rails.logger.error e.message
      end
    end
  end
end
```

実行させるとpidが表示されます。

```
$ rails runner JobTask.execute
3377
```

ここで、pidを確認してみると

```bash
$ ps aux | grep test_command
ogi              3388   0.0  0.0  2432784    580 s001  R+    3:37PM   0:00.00 grep test_command
ogi              3378   0.0  0.0  2442580    580   ??  S     3:35PM   0:00.00 sh -c test_command > test.log 2>&1 &
```

となり、取得した3377とは異なるpid（+1された値）となっていました。

これではpidでキャンセルできません。う〜ん困りました。

## 試行2（実行後にpsでpidを取得する）

欲しいpidはtest_commandのものなので、実行直後にpsでpidを取得しようと考えました。
grepするとgrepのプロセスまで取得してしまうため、それは対象としないようにしました。

```rb:lib/job_task.rb
class JobTask
  class << self
    def execute
      execute_job "test_command > test.log >2&1 &"
    end

    def cancel(pid)
      IO.popen("kill -TERM #{pid}")
      p "canceled!"
    end

    private

    def execute_job(command)
      IO.popen("#{command}"){}
      IO.popen("ps aux | grep -E \"test_command \> test.log\"") do |pipe|
        pipe.readlines.each do |line|
          p line.split[1] if line =~ /^(?!.*grep -E).*$/
        end
      end
    end
  end
end
```

実行します。

```
$ rails runner JobTask.execute
"3836"
```

取得したpidが正しいか確認します。

```bash
$ ps aux | grep test_command
ogi              3847   0.0  0.0  2432784    524 s001  R+    4:08PM   0:00.00 grep test_command
ogi              3836   0.0  0.0  2442580    580   ??  S     4:08PM   0:00.00 sh -c test_command > test.log 2>&1 &
```

今度は欲しいpidが取得できていました。

ではそのpidを使ってキャンセルしてみます。

```bash
$ rails runner "JobTask.cancel(3836)"
```

キャンセルされたか確認します。

```bash
$ ps aux | grep test_command
ogi              3944   0.0  0.0  2423368    184 s001  R+    4:14PM   0:00.00 grep test_command
```

プロセスはkillされていました。

と思っていましたが、落とし穴がありました。

test_command内で呼び出しているコマンド（sleep）は残っていました。

```bash
$ ps aux | grep sleep
ogi              3954   0.0  0.0  2432784    504 s001  R+    4:17PM   0:00.00 grep sleep
ogi              3838   0.0  0.0  2432764    468   ??  S     4:08PM   0:00.00 sleep 100000
```

つまり、対象のプロセスはkillできましたが、そこから呼び出している子プロセスまではkillできていないということです。

## 試行3（echo $!でpid取得と、pgidで関連プロセス全てキャンセル）

まずpid取得ですが、grepとか使わずとも簡単に取得できることがわかりました。

`test_command > test.log 2>&1 & echo $!`

のように、バックグラウンド実行直後に`echo $!`をつなげるだけで、最後に実行したpidが取得できるというのです！
（西脇.rb & 神戸.rbのメンバーに感謝！）

pidが一行で取得できるのでIO.popenではなく\`test_command\`の形に変更できそうです。

さらに、子プロセスまでまとめてkillする方法も教えてもらいました。
gpidを利用する方法です。
（こちらも西脇.rb & 神戸.rbのメンバーが教えてくれました）

**プロセスグループIDの調べ方**

```bash
$ ps -p 4043 -o "pgid"
 PGID
 2947
```

**プロセスグループをkillする方法**

```bash
$ kill -- -2947
```

rubyから実行する場合は、--がうまく解釈されないようなので次のようにします。

```rb
`kill -TERM -2947`
```

これらを反映したコードは次の通りです。

```rb:lib/job_task.rb
class JobTask
  class << self
    def execute
      execute_job "test_command > test.log 2>&1 & echo $!"
    end

    def cancel(pid)
      command = "ps -p #{pid} -o \"pgid\""
      pgid = system_command(command).lines.to_a.last.lstrip.chomp
      if pgid =~ /[0-9]/
        system_command "kill -TERM -#{pgid}"
        p "canceled!"
      else
        Rails.logger.error 'Process was not found'
      end
    end

    private

    def execute_job(command)
      begin
        pid = system_command(command).lstrip.chomp
        if pid =~ /[0-9]/
          p pid
        else
          Rails.logger.error 'command has not pid'
        end
      rescue => e
        Rails.logger.error e.message
      end
    end

    def system_command(command)
      `#{command}`
    end
  end
end
```

再度試します。

```bash
$ rails runner JobTask.execute
"4308"
```

欲しいpidが返ってきました。

```bash
$ ps aux | grep test_command
ogi              4317   0.0  0.0  2423368    216 s001  R+    4:45PM   0:00.00 grep test_command
ogi              4308   0.0  0.0  2442580    568   ??  S     4:44PM   0:00.00 sh -c test_command > test.log 2>&1 & echo $!
$ ps aux | grep sleep
ogi              4324   0.0  0.0  2432784    472 s001  R+    4:45PM   0:00.00 grep sleep
ogi              4309   0.0  0.0  2432764    468   ??  S     4:44PM   0:00.00 sleep 100000
```

キャンセルしてみます。

```bash
$ rails runner "JobTask.cancel(4308)"
$
```

プロセスを確認しています。

```bash
$ ps aux | grep test_command
ogi              4456   0.0  0.0  2424588    388 s001  R+    4:48PM   0:00.00 grep test_command
$ ps aux | grep sleep
ogi              4467   0.0  0.0  2432784    508 s001  R+    4:50PM   0:00.00 grep sleep
```

子プロセスまでちゃんとkillされています。

うまくいった！と思いきや、ここにも落とし穴がありました。

コードでは、

```rb
        system_command "kill -TERM -#{pgid}"
        p "canceled!"
```

とkillの後にログを表示させているのですが、コマンド実行しても何も表示されていませんでした。
デバッガで追いかけても続きを実行できません。
まるで途中で強制終了されたような動きです。

JobTask.execute後のプロセスグループをもう一度確認してみます。

```bash
$ rails runner JobTask.execute
"4520"
$ ps -p 4520 -o "pgid"
 PGID
 4449
$ ps 4449
  PID   TT  STAT      TIME COMMAND
 4449   ??  Ss     0:05.35 spring app    | background_linux_command | started 8 mins ago | development mode
```

グループのルートプロセスがspring（railsを動かしているそのもの）だとわかりました。
なるほど、test_commandとその子プロセスをkillしたつもりが、親のrailsまでkillしていたため続きが実行されていなかったということですね。納得です。

ということで別グループで動かす必要があることがわかりました。

## 試行4（forkして別プロセスで実行する）

railsとは別グループで動かすにはどうすればいいのでしょう？
そういえばデーモンっぽく動かしている[daemon-spawn](https://github.com/alexvollmer/daemon-spawn)はどうしてるんだろう？
と思ってソースを見てみました。

>```rb:daemon_spawn.rb
:
def self.start(daemon, args) #:nodoc:
  :
  fork do
    Process.setsid
    exit if fork
    open(daemon.pid_file, 'w') { |f| f << Process.pid }
    :
  end
  :
end
:
```

なるほど、forkして別プロセスにするわけですね！

これを参考にしてみました。

```rb:lib/job_task.rb
class JobTask
  class << self
    def execute
      execute_job "test_command > test.log 2>&1 & echo $!"
    end

    def cancel(pid)
      command = "ps -p #{pid} -o \"pgid\""
      pgid = system_command(command).lines.to_a.last.lstrip.chomp
      if pgid =~ /[0-9]/
        system_command "kill -TERM -#{pgid}"
        p "canceled!"
      else
        Rails.logger.error 'Process was not found'
      end
    end

    private

    def execute_job(command)
      begin
        fork do
          Process.setsid
          pid = system_command(command).lstrip.chomp
          if pid =~ /[0-9]/
            p pid
          else
            Rails.logger.error 'command has not pid'
          end
        end
      rescue => e
        Rails.logger.error e.message
      end
    end

    def system_command(command)
      `#{command}`
    end
  end
end
```

では実行してみます。

```bash
$ rails runner JobTask.execute
"4877"
$ ps -p 4877 -o "pgid"
 PGID
 4875
$ ps 4875
  PID   TT  STAT      TIME COMMAND
```

ルートプロセスはspringではなくなりました。というより今度はルートプロセスがすでにいなくなっています。

Rails consoleで確認するとわかるのですが、forkさせるとルートプロセスはrubyになっていました。

```bash
$ rails c
Loading development environment (Rails 4.1.8)
irb(main):001:0> JobTask.execute
=> 5003
irb(main):002:0> "5005"

irb(main):003:0* exit
$ ps -p 5005 -o "pgid"
 PGID
 5003
$ ps 5003
  PID   TT  STAT      TIME COMMAND
 5003   ??  Z      0:00.00 (ruby)
```

Rails runnerの処理が終わってrubyプロセスが終了したという認識です。

では、今度はキャンセルしてみます。

```bash
$ rails runner "JobTask.cancel(4877)"
"canceled!"
$ ps aux | grep test_command
ogi              4951   0.0  0.0  2432784    488 s001  R+    5:18PM   0:00.00 grep test_command
$ ps aux | grep sleep
ogi              4958   0.0  0.0  2432784    500 s001  R+    5:18PM   0:00.00 grep sleep
```

今度は意図した動きになりました。

## 試行5（実行させるコマンドをRailsから生成させる）

これまでは実行させるコマンドを~/bin/test_command固定にしていましたが、
実行時に生成したい場合を考えます。

chefのbashブロックがやってるように一時ファイルにコマンドを出力し、
それを実行させるようにします。

```rb:lib/job_task.rb
class JobTask
  class << self
    def execute
      execute_job
    end

    def cancel(pid)
      command = "ps -p #{pid} -o \"pgid\""
      pgid = system_command(command).lines.to_a.last.lstrip.chomp
      if pgid =~ /[0-9]/
        system_command "kill -TERM -#{pgid}"
        p "canceled!"
      else
        Rails.logger.error 'Process was not found'
      end
    end
    private

    def create_command
      command = <<-"EOS"
        echo "start sleep"
        sleep 100000
        echo "end sleep"
      EOS
      script_path = "tmp/test_command"
      File.open(script_path, "w", 0755) do |f|
        f.write command
      end

      # execute background and return pid
      "#{script_path} > tmp/test.log 2>&1 & echo $!"
    end

    def execute_job
      begin
        fork do
          Process.setsid
          pid = system_command(create_command).lstrip.chomp
          if pid =~ /[0-9]/
            p pid
          else
            Rails.logger.error 'command has not pid'
          end
        end
      rescue => e
        Rails.logger.error e.message
      end
    end

    def system_command(command)
      `#{command}`
    end
  end
end
```

実行してみます。

```bash
$ rails runner JobTask.execute
"5507"
$ ps aux | grep test_command
ogi              5522   0.0  0.0  2432784    496 s001  R+    5:49PM   0:00.00 grep test_command
ogi              5507   0.0  0.0  2442580    568   ??  S     5:49PM   0:00.00 sh -c tmp/test_command > tmp/test.log 2>&1 & echo $!
$ ps aux | grep sleep
ogi              5529   0.0  0.0  2424588    404 s001  R+    5:49PM   0:00.00 grep sleep
ogi              5508   0.0  0.0  2432764    468   ??  S     5:49PM   0:00.00 sleep 100000
```

キャンセルしてみます。

```bash
$ rails runner "JobTask.cancel(5507)"
"canceled!"
$ ps aux | grep test_command
ogi              5572   0.0  0.0  2442000    616 s001  S+    5:50PM   0:00.00 grep test_command
$ ps aux | grep sleep
ogi              5579   0.0  0.0  2432784    512 s001  R+    5:50PM   0:00.00 grep sleep
```

実行用のファイルとログも確認します。

```bash
$ ls tmp/
cache		test.log	test_command
$ cat tmp/test_command
        echo "start sleep"
        sleep 100000
        echo "end sleep"
$ cat tmp/test.log
start sleep
```

意図した動きになりました。


## 最後に

試行錯誤でやりたいことを実現している状態なので、
もっと良い方法を知っている方がいましたら教えてもらえるとうれしいです。