【Python入門】デコレータで関数の実行ログを出力してみよう！

はじめに

Pythonにはデコレータという便利な機能があります。
デコレータを使うと、関数の前後に共通処理を追加できるため、ログ出力や処理時間の計測などを簡単に実装できます。

今回は、関数の実行ログを出力するデコレータを作ってみましょう！
初心者の方でもわかりやすいよう、基礎から実例まで解説します。

---

目次

1. デコレータとは？
2. デコレータの基本構造
3. 関数の実行ログを出力するデコレータ
4. 実行結果
5. 応用例：処理時間を測るデコレータ
6. まとめ

---

1. デコレータとは？

デコレータは、関数を受け取り、処理を追加して返す関数です。
簡単に言うと、**「関数にちょい足しする仕組み」**です。

例えば、次のようなイメージです：

def decorator(func):
    def wrapper():
        # 関数の前処理
        func()
        # 関数の後処理
    return wrapper

@decorator
def hello():
    print("こんにちは！")

@decorator は hello = decorator(hello) と同じ意味です。
この仕組みを使って、関数の前後にログを出すことができます。

---

2. デコレータの基本構造

まずはシンプルな例を見てみましょう。

def my_decorator(func):
    def wrapper():
        print("処理前です")
        func()
        print("処理後です")
    return wrapper

@my_decorator
def hello():
    print("こんにちは！")

hello()

実行結果

処理前です
こんにちは！
処理後です

このように、デコレータを使うと、関数の前後に好きな処理を追加できます。

---

3. 関数の実行ログを出力するデコレータ

それでは、関数の実行ログを出力するデコレータを作ってみます。
実行時刻、関数名、引数、戻り値をログに表示します。

import functools
import datetime

def log_execution(func):
    @functools.wraps(func)  # 元の関数情報を保持する
    def wrapper(*args, **kwargs):
        start_time = datetime.datetime.now()
        print(f"[{start_time}] 関数 `{func.__name__}` 開始")
        print(f"引数: args={args}, kwargs={kwargs}")

        result = func(*args, **kwargs)

        end_time = datetime.datetime.now()
        print(f"[{end_time}] 関数 `{func.__name__}` 終了")
        print(f"戻り値: {result}")
        print("-" * 40)
        return result
    return wrapper

# デコレータを使う関数
@log_execution
def greet(name, age):
    print(f"こんにちは、{name}さん！年齢は{age}歳ですね。")
    return f"Hello, {name}!"

@log_execution
def add(a, b):
    return a + b

# 実行
greet("太郎", age=30)
add(5, 7)

---

4. 実行結果

[2025-08-25 12:34:56.123456] 関数 `greet` 開始
引数: args=('太郎',), kwargs={'age': 30}
こんにちは、太郎さん！年齢は30歳ですね。
[2025-08-25 12:34:56.123789] 関数 `greet` 終了
戻り値: Hello, 太郎!
----------------------------------------
[2025-08-25 12:34:56.123890] 関数 `add` 開始
引数: args=(5, 7), kwargs={}
[2025-08-25 12:34:56.123999] 関数 `add` 終了
戻り値: 12
----------------------------------------

---

5. 応用例：処理時間を測るデコレータ

デコレータはログだけでなく、関数の処理時間を計測する用途にもよく使われます。

import time
import functools

def timer(func):
    @functools.wraps(func)
    def wrapper(*args, **kwargs):
        start = time.time()
        result = func(*args, **kwargs)
        end = time.time()
        print(f"関数 `{func.__name__}` の実行時間: {end - start:.4f}秒")
        return result
    return wrapper

@timer
def slow_function():
    time.sleep(2)
    print("処理が完了しました")

slow_function()

実行結果

処理が完了しました
関数 `slow_function` の実行時間: 2.0001秒

---

6. まとめ

• デコレータは「関数の前後に処理を追加する仕組み」
• @デコレータ名 をつけるだけで、簡単に共通処理を実装できる
• ログ出力、実行時間計測、認証チェックなどでよく使われる