Python – デコレータ (Decorator)
本記事ではPythonのデコレータ（Decorator）を整理します。読み進める前にファーストクラス関数とクロージャの理解が必要です。これらに不慣れな場合は、まず以下の記事を参照してください。
Python – ファーストクラス関数 (First Class Function)
Python – クロージャ (Closure)
デコレータとは何でしょうか。辞書的な意味では「装飾家」または「インテリアデザイナー」を指します。名前の通り、既存のコードに様々な機能を付加して使うためのPython構文と理解してください。デコレータの概念自体は複雑ではないため、サンプルコードで使い方を見ていきます。
まず、お好きなディレクトリの中に decorator.py というPythonファイルを作って、下のコードを保存してください。
def outer_function(msg):
def inner_function():
print(msg)
return inner_function
hi_func = outer_function('Hi')
bye_func = outer_function('Bye')
hi_func()
bye_func()コードを保存したら、ターミナルやコマンドプロンプトを開いて、コードが保存されたディレクトリに移動し、次のコマンドでプログラムを実行してください。
$ python decorator.py
Hi
Bye前回の講座である Python – クロージャ (Closure) を読まれた方なら、上のコードを理解しているはずです。デコレータのコードも上のコードととても似ています。ただ、関数を別の関数の引数として渡すという点が少し違います。最も簡単なデコレータの例を見てみましょう。次のコードを保存して実行してください。
def decorator_function(original_function): # 1
def wrapper_function(): # 5
return original_function() # 7
return wrapper_function # 6
def display(): # 2
print('display 関数が実行されました。') # 8
decorated_display = decorator_function(display) # 3
decorated_display() # 4$ python decorator.py
display 関数が実行されました。上のコードは次のような内容です。デコレータ関数である decorator_function と通常の関数である display を、#1と#2でそれぞれ定義しました。次に#3で、decorated_display という変数に、display 関数を引数とする decorator_function を実行した戻り値を代入しました。もちろんこの戻り値は wrapper_function ですね。ここで wrapper_function 関数はまだ実行されていません。decorated_display 変数の中で呼び出されるのを待っているのです。そして#4の decorated_display() を通して wrapper_function を呼び出すと、#5で定義された wrapper_function が呼び出されます。すると#7で original_function である display 関数が呼び出され、#8の print 関数が呼び出されて文字列が出力されるのです。
ここまで読むと少し息切れしますね。ところで、この複雑に見えるデコレータを一体なぜ使うのでしょうか。その理由は、講座の冒頭でも説明したように、すでに作られている既存のコードを修正することなく、ラッパー (wrapper) 関数を使って様々な機能を追加できるからです。例を見てみましょう。
def decorator_function(original_function):
def wrapper_function():
print('{} 関数が呼び出される前です。'.format(original_function.__name__))
return original_function()
return wrapper_function
def display_1():
print('display_1 関数が実行されました。')
def display_2():
print('display_2 関数が実行されました。')
display_1 = decorator_function(display_1) # 1
display_2 = decorator_function(display_2) # 2
display_1()
print()
display_2()$ python decorator.py
display_1 関数が呼び出される前です。
display_1 関数が実行されました。
display_2 関数が呼び出される前です。
display_2 関数が実行されました。上の例のように、一つのデコレータ関数を作って、display_1 と display_2 の二つの関数に機能を追加できるのです。ところで、一般的に上の例の #1 や #2 のような書き方はあまり使わず、@ 記号とデコレータ関数の名前を付けるシンプルな構文を使います。上のコードは次のコードのように簡潔にできます。
def decorator_function(original_function):
def wrapper_function():
print('{} 関数が呼び出される前です。'.format(original_function.__name__))
return original_function()
return wrapper_function
@decorator_function # 1
def display_1():
print('display_1 関数が実行されました。')
@decorator_function # 2
def display_2():
print('display_2 関数が実行されました。')
# display_1 = decorator_function(display_1) # 3
# display_2 = decorator_function(display_2) # 4
display_1()
print()
display_2()$ python decorator.py
display_1 関数が呼び出される前です。
display_1 関数が実行されました。
display_2 関数が呼び出される前です。
display_2 関数が実行されました。#3と#4の代わりに、#1と#2に@記号を使ったデコレータ構文が追加され、コードが少しシンプルになったのが分かります。
ところで、次のコードの display_info 関数のように引数を持つ関数をデコレートしたいときはどうすればよいでしょうか。ファイルを修正して実行してみましょう。
def decorator_function(original_function):
def wrapper_function():
print('{} 関数が呼び出される前です。'.format(original_function.__name__))
return original_function()
return wrapper_function
@decorator_function
def display():
print('display 関数が実行されました。')
@decorator_function
def display_info(name, age):
print('display_info({}, {}) 関数が実行されました。'.format(name, age))
display()
print()
display_info('John', 25)$ python decorator.py
display 関数が呼び出される前です。
display 関数が実行されました。
Traceback (most recent call last):
File "decorator.py", line 21, in <module>
display_info('John', 25)
TypeError: wrapper_function() takes 0 positional arguments but 2 were givenwrapper_function は引数を受け取らないのに2つの引数が渡されたという型エラーが発生しました。次のようにコードを修正すれば問題は解決します。
def decorator_function(original_function):
def wrapper_function(*args, **kwargs): #1
print('{} 関数が呼び出される前です。'.format(original_function.__name__))
return original_function(*args, **kwargs) #2
return wrapper_function
@decorator_function
def display():
print('display 関数が実行されました。')
@decorator_function
def display_info(name, age):
print('display_info({}, {}) 関数が実行されました。'.format(name, age))
display()
print()
display_info('John', 25)$ python decorator.py
display 関数が呼び出される前です。
display 関数が実行されました。
display_info 関数が呼び出される前です。
display_info(John, 25) 関数が実行されました。#1と#2に引数を追加して問題を解決しました。
デコレータには、このような関数形式以外にもクラス形式を使うこともできます。一度見てみましょう。
# def decorator_function(original_function):
# def wrapper_function(*args, **kwargs):
# print '{} 関数が呼び出される前です。'.format(original_function.__name__)
# return original_function(*args, **kwargs)
# return wrapper_function
class DecoratorClass: # 1
def __init__(self, original_function):
self.original_function = original_function
def __call__(self, *args, **kwargs):
print('{} 関数が呼び出される前です。'.format(self.original_function.__name__))
return self.original_function(*args, **kwargs)
@DecoratorClass # 2
def display():
print('display 関数が実行されました。')
@DecoratorClass # 3
def display_info(name, age):
print('display_info({}, {}) 関数が実行されました。'.format(name, age))
display()
print()
display_info('John', 25)$ python decorator.py
display 関数が呼び出される前です。
display 関数が実行されました。
display_info 関数が呼び出される前です。
display_info(John, 25) 関数が実行されました。#1で DecoratorClass を定義した後、#2、#3で @DecoratorClass に変更すると、decorator_function を使ったときと同じ結果が出力されているのが分かります。しかしクラス形式のデコレータはそれほど多くは使われず、通常は関数形式が多く使われます。クラス形式もあるという程度を覚えておけば良いでしょう。
これでデコレータが何なのか感じが掴めましたか。ところが、多くの人がデコレータを理解はしたものの、実際のプロジェクトでどのように使えばよいか分からない、という場合が多くあります。次の例を通して、実際のプロジェクトでデコレータがどのように使われるか見ていきましょう。
一般的にデコレータは、ログを残したり、ユーザーのログイン状態などを確認してログイン状態でなければログインページにリダイレクト（redirect）するためによく使われます。また、プログラムのパフォーマンスをテストするためにもよく使われます。LinuxやUnixのサーバ管理者は、スクリプトの実行時間を測定するために、次のような date と time コマンドをよく使います。
$ date; time sleep 1; date
Thu Sep 8 00:13:28 JST 2016
real 0m1.007s
user 0m0.001s
sys 0m0.001s
Thu Sep 8 00:13:29 JST 2016デコレータを使って上のようなロギング機能を作ることができますが、一度作ってみましょう。
import datetime
import time
def my_logger(original_function):
import logging
filename = '{}.log'.format(original_function.__name__)
logging.basicConfig(handlers=[logging.FileHandler(filename, 'a', 'utf-8')],
level=logging.INFO)
def wrapper(*args, **kwargs):
timestamp = datetime.datetime.now().strftime('%Y-%m-%d %H:%M')
logging.info('[{}] 実行結果 args - {}, kwargs - {}'.format(timestamp, args, kwargs))
return original_function(*args, **kwargs)
return wrapper
@my_logger
def display_info(name, age):
time.sleep(1)
print('display_info({}, {}) 関数が実行されました。'.format(name, age))上のコードを実行すると、ターミナルに次のように出力され、decorator.py Pythonファイルが保存されたディレクトリに display_info.log という名前のログファイルが生成されます。プログラムを実行してください。
$ python decorator.py
display_info(John, 25) 関数が実行されました。ログファイルの中には次のような情報が記録されているのが分かります。
INFO:root:[2021-10-03 21:13] 実行結果 args - ('John', 25), kwargs - {}今度は、別のデコレータをもう一つ追加して、プログラムが実行される時間を測ってみましょう。
import datetime
import time
def my_logger(original_function):
import logging
filename = '{}.log'.format(original_function.__name__)
logging.basicConfig(handlers=[logging.FileHandler(filename, 'a', 'utf-8')],
level=logging.INFO)
def wrapper(*args, **kwargs):
timestamp = datetime.datetime.now().strftime('%Y-%m-%d %H:%M')
logging.info(
'[{}] 実行結果 args - {}, kwargs - {}'.format(timestamp, args, kwargs))
return original_function(*args, **kwargs)
return wrapper
def my_timer(original_function): # 1
import time
def wrapper(*args, **kwargs):
t1 = time.time()
result = original_function(*args, **kwargs)
t2 = time.time() - t1
print('{} 関数が実行された総時間: {} 秒'.format(original_function.__name__, t2))
return result
return wrapper
@my_timer # 2
def display_info(name, age):
time.sleep(1)
print('display_info({}, {}) 関数が実行されました。'.format(name, age))
display_info('John', 25)#1で my_timer という名前の新しいデコレータを定義し、#2で display_info 関数に適用しました。プログラムを実行してみましょう。
$ python decorator.py
display_info(John, 25) 関数が実行されました。
display_info 関数が実行された総時間: 1.00157594681 秒1秒かかりました。
それでは今度は、my_logger と my_timer の二つのデコレータを同時に使ってみましょう。
import datetime
import time
def my_logger(original_function):
import logging
filename = '{}.log'.format(original_function.__name__)
logging.basicConfig(handlers=[logging.FileHandler(filename, 'a', 'utf-8')],
level=logging.INFO)
def wrapper(*args, **kwargs):
timestamp = datetime.datetime.now().strftime('%Y-%m-%d %H:%M')
logging.info(
'[{}] 実行結果 args - {}, kwargs - {}'.format(timestamp, args, kwargs))
return original_function(*args, **kwargs)
return wrapper
def my_timer(original_function):
import time
def wrapper(*args, **kwargs):
t1 = time.time()
result = original_function(*args, **kwargs)
t2 = time.time() - t1
print('{} 関数が実行された総時間: {} 秒'.format(original_function.__name__, t2))
return result
return wrapper
@my_logger # 1
@my_timer # 2
def display_info(name, age):
time.sleep(1)
print('display_info({}, {}) 関数が実行されました。'.format(name, age))
display_info('John', 25)$ python decorator.py
display_info(John, 25) 関数が実行されました。
display_info 関数が実行された総時間: 1.00419592857 秒INFO:root:[2021-10-03 21:13] 実行結果 args - ('John', 25), kwargs - {}#1、#2でデコレータ2つを一気に使いました。ターミナル上の実行結果は先ほどと同じように出力されました。ところが、ログファイルには何も記録されていません。代わりに wrapper.log という名前のログファイルが生成され、その中に次のようなログが残っていました。
INFO:root:[2021-10-03 21:17] 実行結果 args - ('John', 25), kwargs - {}うーん…なぜでしょうか。それでは今度はデコレータの順序を入れ替えてみましょうか。
from functools import wraps
import datetime
import time
def my_logger(original_function):
import logging
filename = '{}.log'.format(original_function.__name__)
logging.basicConfig(handlers=[logging.FileHandler(filename, 'a', 'utf-8')],
level=logging.INFO)
@wraps(original_function) # 1
def wrapper(*args, **kwargs):
timestamp = datetime.datetime.now().strftime('%Y-%m-%d %H:%M')
logging.info(
'[{}] 実行結果 args - {}, kwargs - {}'.format(timestamp, args, kwargs))
return original_function(*args, **kwargs)
return wrapper
def my_timer(original_function):
import time
@wraps(original_function) # 2
def wrapper(*args, **kwargs):
t1 = time.time()
result = original_function(*args, **kwargs)
t2 = time.time() - t1
print('{} 関数が実行された総時間: {} 秒'.format(original_function.__name__, t2))
return result
return wrapper
@my_timer
@my_logger
def display_info(name, age):
time.sleep(1)
print('display_info({}, {}) 関数が実行されました。'.format(name, age))
display_info('Jimmy', 30) # 3INFO:root:[2021-10-03 21:13] 実行結果 args - ('John', 25), kwargs - {}
INFO:root:[2021-10-03 21:20] 実行結果 args - ('John', 25), kwargs - {}今度はログファイルにきちんとロギングされていますね。あっ！ところが、ターミナルに出力された結果がちょっとおかしいですね。
$ python decorator.py
display_info(John, 25) 関数が実行されました。
wrapper 関数が実行された総時間: 1.0019299984 秒display_info ではなく wrapper が出力されました。だんだん迷宮に迷い込んでいきます。笑
このようになる理由はとても単純です。複数のデコレータをスタックして使うと、下側のデコレータから実行されるのですが、上のコードの場合は#1の my_logger が先に実行され、#2の my_timer に#3で wrapper 関数を引数としてreturnするために起こる現象です。#4では original_function はもちろん wrapper 関数と同じです。
このような現象を防ぐために作られたモジュールがあるのですが、それが functools モジュールの wraps デコレータです。一度使ってみましょう。
from functools import wraps
import datetime
import time
def my_logger(original_function):
import logging
filename = '{}.log'.format(original_function.__name__)
logging.basicConfig(handlers=[logging.FileHandler(filename, 'a', 'utf-8')],
level=logging.INFO)
@wraps(original_function) # 1
def wrapper(*args, **kwargs):
timestamp = datetime.datetime.now().strftime('%Y-%m-%d %H:%M')
logging.info(
'[{}] 実行結果 args - {}, kwargs - {}'.format(timestamp, args, kwargs))
return original_function(*args, **kwargs)
return wrapper
def my_timer(original_function):
import time
@wraps(original_function) # 2
def wrapper(*args, **kwargs):
t1 = time.time()
result = original_function(*args, **kwargs)
t2 = time.time() - t1
print('{} 関数が実行された総時間: {} 秒'.format(original_function.__name__, t2))
return result
return wrapper
@my_timer
@my_logger
def display_info(name, age):
time.sleep(1)
print('display_info({}, {}) 関数が実行されました。'.format(name, age))
display_info('Jimmy', 30) # 3#1、#2でwrapsデコレータで2つのwrapper関数をデコレートし、本当にうまく動作するかを正確に確認するために、#3の名前と年齢を変えてみました。
$ python decorator.py
display_info(Jimmy, 30) 関数が実行されました。
display_info 関数が実行された総時間: 1.013833999633789 秒INFO:root:[2021-10-03 21:13] 実行結果 args - ('John', 25), kwargs - {}
INFO:root:[2021-10-03 21:20] 実行結果 args - ('John', 25), kwargs - {}
INFO:root:[2021-10-03 21:27] 実行結果 args - ('Jimmy', 30), kwargs - {}私たちが望む結果が、何の問題もなくターミナルとログファイルに出力されました。
ここまでがデコレータの基本的な使い方です。概念を理解しても実際に使わないと定着しにくいため、繰り返し練習し、実際のプロジェクトに適用することをおすすめします。
次回はPythonのジェネレータ（Generator）を取り上げます。