joblibの並列化関数を利用する場合、並列実行される関数の中のprint()文が?

Question

joblibの並列化関数を利用する場合、並列実行される関数の中のprint()文が全部出力できなくなります。
原因は何でしょうか。
この場合中間結果を確認したい場合どうすれば良いのでしょうか。

環境 Google Colaboratory

実行文の例：

Parallel(n_jobs=-1,verbose=11)(delayed(myFunc)(x) for x in range(100) )

myFunc()中のprint()文が全部自動的に無効になってしまいました。

Comments

[jbpb0]

以下はjupyterの場合ですが、google colabも同じかも
https://stackoverflow.com/questions/55955330/printed-output-not-displayed-when-using-joblib-in-jupyter-notebook

Answer 1

joblib については詳しく知りませんが、サブプロセス側でのprint デバッグは
logging モジュールの QueueHandler 等を用いて、メインプロセス側でまとめて出力するように構成します。
⇛ サンプルコードは、ロギングクックブックの複数プロセスからのログを参照してください。

問題の原因は、サブプロセスの利用方法次第では、
実行環境で設定された python上のsys.stdout 等のリダイレクトが適応されない、という問題です。
google colab 以外にも IDE 内の実行でも同様の症状が確認されています。
（解決可能な不具合ではなく、実装による制限のようです）

Pararell の引数に backend="multithread" を指定すると、print() の表示自体は出来るようになりますが、
マルチプロセスでは実行タイミングが保証されない為、ログ出力が崩れる原因にも成りかねません。

デバッグで一時的に出力が見たいだけの場合等は、printが手軽かもしれませんが、
マルチスレッド・マルチプロセスではlogging モジュールをお勧めします。

実際の用途を想定すると
外部ライブラリ内で logging モジュールを使っている場合もあるので、
例えばサブプロセス側でそういったライブラリを使う場合、
正しく logging の設定を構成できないと、ログ出力に気付かない
もしくは、ログが壊れる、といったことが起こる可能性があります。

---

関連:

• logging cookbook - 複数のプロセスからの単一ファイルへのログ記録
• Google Colaboratory でログファイルを出力する方法
• problem with logging module in google colab

FileHandler の代わりに StreamHandler を使うと notebook 内に出力できますが、
ログが大量になる時に、便利そうな記事を見つけたので関連として紹介。
他、Google Colab (Jupyter 環境等) での logging モジュール利用の注意点もあります。

Answer 2

Google colabで試した結果を載せます。
Backendがloky以外なら表示できます。
※Stackoverflowにて記事発見。「lokyモジュールがそうさせている」とのこと。

後はお好みでどうぞ。

import joblib

# # backend: multithread, expected one of ['loky', 'multiprocessing', 'sequential', 'threading']
# back_end = "loky" # 表示されない。割愛した時のデフォルトの引数
# back_end = "multiprocessing" # 表示される。並列処理の特性上、必ず順番通りになるわけではない。
# back_end = "sequential" # 表示される。joblibのガワはかぶっていても並列処理はしていないので、必ず順番通りに表示される。
back_end = "threading" # 表示される。並列処理の特性上、必ず順番通りになるわけではない（はずなのに、Google Colabだと順番通りに…）。

def myFunc(val):
    print("Child:",val,flush=True) # 質問事項の検証用
    return val

ans = joblib.Parallel(n_jobs=-1,verbose=0,backend=back_end)(joblib.delayed(myFunc)(x) for x in range(100) )
print("ans:",ans)

Comments

[insecticide]

＞手元の環境ではちゃんと表示されています。

Google　Colaboratory も大丈夫でしょうか？

[退会済みユーザー]

Windows x Python3.6では確認しました。
Google Colabで試したところ途中経過はprintされませんでした。

引数指定を明示的にすると表示できるようになりました。回答を修正します。

[insecticide]

お返事ありがとうございます。
＞Backendがloky以外なら表示できます。

自分の印象ではBackendがlokyであるのはお決まりのようなもんですけれども？

[退会済みユーザー]

> 自分の印象ではBackendがlokyであるのはお決まりのようなもんですけれども？
「お決まり」のモジュールなのにこんなすぐわかりそうなバグがすり抜けてしまった理由は、stackoverflowのコメントにありますが、恐らくOSやモジュールのバージョンの微妙な関係性で成り立っているバグだから、と私は思っています。

しかも、その「お決まり」のlokyが参照する（恐らく内部でsubprocessして並列処理させる時の依存関係にある）ipythonモジュールがprintしようとすると、（Jupyter notebookやGoogle colabの表示回りという限定環境において）表示されなくなるというわけです。だから、「お決まり」の引数指定なし=標準でPrintされない状態が発生していると思っています。Ipythonの作者がWindwos環境でしかデバグしなかっただとか、バグをすり抜ける特定のバージョンのモジュールを使っていた、とかそっち系の話と思います。

その上に、「どうせ引数に『お決まり』のlokyではなく、multiprocessingやthreadingを指定すれば回避できるんだろ？」という気持ちが使用者界隈に横たわっていて、バグレポートが出されていても放置され続けている、バグレポートも止まっている、が恐らくが実態です。

―ーという状況下にありながら、それでもなお
> 自分の印象ではBackendがlokyであるのはお決まりのようなもんですけれども？
というように、「お決まり」のくせいにおかしいじゃないか、ということでしたら以下のgithubのリポジトリでバグレポートとソースコードのどの辺がおかしいかソースコードのどこを直せばいいといった指摘すれば直してもらえるのではないでしょうか。
https://github.com/ipython/ipykernel/issues/402

Answer 3

マルチプロセスの場合、print 文の表示がタイミング的乱れがあるという印象でした。

Comments

[teamikl]

タイミングに乱れがある（非同期の特性）と
本題（表示されない問題の原因:サブプロセスに標準出力のリダイレクトが伝搬されていない）は別問題です。

一応、表示させるだけなら backend="multiprocessing" 指定だけでも対応可能です。
（但し、タイミング問題は潜在的な問題として残ります）

[insecticide]

> backend="multiprocessing" 指定だけでも対応可能です。

これは有難いですね。
試してみたらOKです❣
本当にありがとうございました。

[退会済みユーザー]

print(○○,flush＝True)でPython側でのラグは減らせます。
が、Multiprosessingは同時性を犠牲にしてその代わりに並列化して早く済ませる処理です。タイミングを期待するものではないです。完全に揃えるならback_end = "sequential"で並列処理を止める必要があります。