PowerShell から Python をバックグラウンド実行する

Question

内容

PowerShellを使用して、同時に複数のPythonを並列実行したいと考えています。
Start-Jobを使用しましたが、並列ではなく直列で実行されている状況です。
調べても原因がわかっていないため、アドバイスをいただきたくご質問です。

実行の流れ

1. PowerSell から .\Execute.ps1を実行
2. Execute.ps1 がバックグラウンドで Before.pyを実行
3. Execute.ps1 がバックグラウンドで After.pyを実行

# ファイル名：Execute.ps1

$py_before = {py -3 Before.py}
$py_after = {py -3 After.py}

# バックグラウンド実行
Start-Job -Name "py_before" $py_before
Start-Job -Name "py_after" $py_after

# バックグラウンドJobの終了を待つ
Get-Job -name "py_*" | Wait-Job | Receive-Job

# Jobの終了
Remove-Job -name "py_*" -force

# ファイル名：Before.py

import time

for i in range(5):
    print("before: " + str(i))
    time.sleep(3)
print("before: finish")

# ファイル名：After.py

import time

for i in range(5):
    print("after: " + str(i))
    time.sleep(3)
print("after: finish")

実行結果

before: 0
before: 1
before: 2
before: 3
before: 4
before: finish
after: 0
after: 1
after: 2
after: 3
after: 4
after: finish

期待する実行結果

並列で実行されることを期待しているため、以下のような出力がされることを想定しています。

before: 0
after: 0
before: 1
after: 1
before: 2
after: 2
before: 3
after: 3
before: 4
after: 4
before: finish
after: finish

Answer 1

ループ内のprintで時刻を表示させてみれば並列実行されていることが分かります。

行が混ざらないのは、receive-jobが直列で実行されるからでしょう。

Comments

[otn]

かぶったか。

[IOError]

otn さん
毎度ご回答いただきありがとうございます。
今回の原因が Receive-Job 側にあるとは思いもよりませんでした。
(終了を待つだけで、途中のログは混ざって表示されるものと思い込んでいました)
特に並列処理実行時には、タイムスタンプを表示することで確認できることも新たな観点として覚えておきます。
ありがとうございました。

Answer 2

Receive-Job でジョブ毎に取得しているだけです。
次のように、時間を出力してみてください。

# ファイル名：Before.py

import time

for i in range(5):
    print("before: " + str(i) + ": " + str(time.time()))
    time.sleep(3)
print("before: finish")

出力

before: 0: 1605789093.1365125
before: 1: 1605789096.1372843
before: 2: 1605789099.1381838
before: 3: 1605789102.1381881
before: 4: 1605789105.1382692
before: finish
after: 0: 1605789093.2033725
after: 1: 1605789096.2043052
after: 2: 1605789099.2047946
after: 3: 1605789102.205457
after: 4: 1605789105.2055109
after: finish

Comments

[IOError]

Zuishin さん
ご回答いただきありがとうございます。
Receive-Job が Job ごとに結果を出力しているだけで、内部的には並列で処理されていたんですね。
Start-Job の呼び出し方に問題があるとばかり思い込んでおりました。
勉強になりました、ありがとうございます。

[IOError]

Zuishin さん
たびたび申し訳ありません。
手元でタイムスタンプを表示させたのですが、載せていただいた通りにならず、before: 4: xxx の3秒後に after: 1: xxx が表示されていました。
そもそも環境に依存するようなことがあるのでしょうか。
(特にスレッド数に関する設定等)

[Zuishin]

何か変えましたか？

[IOError]

Zuishin さん
いえ、python の print にタイムスタンプを追加しただけです。

[Zuishin]

Execute.ps1 をこの質問からコピペして上書きしてみてください。

[IOError]

Zuishin さん
それも行ってみましたが、やはり after: 1 のタイムスタンプは befre: 4 の3秒後になっています。

[Zuishin]

実際に使っているスクリプトをすべて質問に掲載し、結果もコピペしてください。あと $PSVersionTable と。

[Zuishin]

ログインしているのに返事がないということは、やっぱり違うものを動かしているわけですね。

Start-Job は内容を別プロセスで起動して自身はすぐに終了します。一番目のジョブの終了を待ってから次のジョブを起動するようなことはしません。

Execute.ps1 が同じものだとしたら、Python スクリプトの方でロックのかかった処理をしているなどの原因で、スクリプト自身が同期しているか、リソース不足など何らかの原因で遅延実行されているかが考えられます。どちらもこのコードで起こるとは考えにくいものです。