はじめに
アノテーションの髙嶋です。
今回はPythonで書いたプログラムを実行した場合に、各ファイルが処理される順番について確認してみた話を書きます。
logging設定をする際に各ファイルにログレベル設定の記述されていると想定通りのログレベルにならなかったり、テストコードを書く際にMockしようとしても意図した結果にならなかったり、ということがありました。
「なんでだろう？」を考えた際に、自分で考えている処理タイミングと実際の処理タイミングが異なるのではないか？と気になったところになります。
試してみた
実際にPythonのコードを準備して、各ファイルがどういう順で処理されるかを試してみました。
sample1.pyというファイルを起点とし、他ファイルをimportしたり、各関数を実行したりしています。
その際に、各ファイルにprint()によるログ出力を埋め込み、どういう順で実行されているかを見える化できるようにしています。
実行環境
今回使用したPythonのバージョンは下記です。
python --version Python 3.11.4
ファイル内容
準備したファイルは下記の通りです。
./
├─ sample1.py
├─ sample2.py
├─ sample3.py
└─ sample4.pysample1.py
from sample2 import Sample2, huga2
from sample4 import Sample4, huga4
print('sample1-開始')
sample2 = Sample2()
class Sample1():
print('sample1-クラス先頭')
def __init__(self):
print('sample1-コンストラクタ')
def hoge(self):
print('sample1-hoge')
sample2.hoge()
sample4 = Sample4()
sample4.hoge()
huga1()
huga2()
huga4()
print('sample1-クラス末尾')
def huga1():
print('sample1-huga')
if __name__ == '__main__':
print('sample1-処理実行前')
sample = Sample1()
sample.hoge()
print('sample1-処理実行後')
print('sample1-終了')sample2.py
from sample3 import Sample3
from sample4 import Sample4
print('sample2-開始')
class Sample2():
print('sample2-クラス先頭')
sample3 = Sample3()
def __init__(self):
print('sample2-コンストラクタ')
self.sample3 = Sample3()
def hoge(self):
print('sample2-hoge')
self.sample3.hoge()
sample4 = Sample4()
sample4.hoge()
print('sample2-クラス末尾')
def huga2():
print('sample2-huga')
print('sample2-終了')sample3.py
print('sample3-開始')
class Sample3():
print('sample3-クラス先頭')
def __init__(self):
print('sample3-コンストラクタ')
def hoge(self):
print('sample3-hoge')
print('sample3-クラス末尾')
def huga3():
print('sample3-huga')
print('sample3-終了')sample4.py
print('sample4-開始')
class Sample4():
print('sample4-クラス先頭')
def __init__(self):
print('sample4-コンストラクタ')
def hoge(self):
print('sample4-hoge')
print('sample4-クラス末尾')
def huga4():
print('sample4-huga')
print('sample4-終了')実行結果
実行コマンド
# python sample1.py
ログ出力結果
sample3-開始 sample3-クラス先頭 sample3-クラス末尾 sample3-終了 sample4-開始 sample4-クラス先頭 sample4-クラス末尾 sample4-終了 sample2-開始 sample2-クラス先頭 sample3-コンストラクタ sample2-クラス末尾 sample2-終了 sample1-開始 sample2-コンストラクタ sample3-コンストラクタ sample1-クラス先頭 sample1-クラス末尾 sample1-処理実行前 sample1-コンストラクタ sample1-hoge sample2-hoge sample3-hoge sample4-コンストラクタ sample4-hoge sample4-コンストラクタ sample4-hoge sample1-huga sample2-huga sample4-huga sample1-処理実行後 sample1-終了
確認できたこと
- import時点でファイルの内容が読み込まれ、関数・メソッド外に記述した処理が実行される
sample1-開始ログより先にsample3-開始ログが出力されている
- 複数ファイルから同一ファイルをimportしても、読み込まれるのは最初の1回のみ
sample4.pyはsample1.pyとsample2.pyからimportしているが、sample4-開始ログは1回しか出力されていない
- 関数・メソッドの処理は呼び出した時のみ実行される（それはそうだ）
まとめ
import時点で処理が実行されているというのが、今回得られた気づきでした。
→ そのファイル内の処理が必要になった時に読み込まれるのかな？と思っていた。
もし、公式ドキュメントとかに書かれている内容だったら失礼しました。（確認してない）
テストコードを書いてる際に、Mockしているはずなのにうまくいかないというのがあったのですが、実はMockしたい箇所の処理がMockする前に既に実行されていたということでした。
なので、関数・メソッド外に処理を記述するのはできるだけ避けよう、とも思いました。（もしくは「こう書くといい」という書き方があれば知りたいです）
また、今回の挙動に関しては言語やバージョンによって異なる可能性がありますのでご注意ください。
アノテーション株式会社について
アノテーション株式会社は、クラスメソッド社のグループ企業として「オペレーション・エクセレンス」を担える企業を目指してチャレンジを続けています。「らしく働く、らしく生きる」のスローガンを掲げ、様々な背景をもつ多様なメンバーが自由度の高い働き方を通してお客様へサービスを提供し続けてきました。現在当社では一緒に会社を盛り上げていただけるメンバーを募集中です。少しでもご興味あれば、アノテーション株式会社WEBサイトをご覧ください。
2
