Python Decorator for Function Execution Timing and Call Hierarchy Logging

stopwatch.py

from functools import wraps
import time
import alog

level = 0
def stopwatch(func):
    @wraps(func)
    def wrapper(*args, **kwargs):
        global level
        level += 1
        alog.info(f"({level}) ENTER {func.__name__}")
        t1 = time.perf_counter()
        try:
            result = func(*args, **kwargs)
        finally:
            elapsed = time.perf_counter() - t1
            alog.info(f"({level}) LEAVE {func.__name__} (took: {elapsed: 0.6f} usec)")
            level -= 1
        return result
    return wrapper


@stopwatch
def hoge(a):
    return f"HOGE: {fuga(a)}"

@stopwatch
def fuga(a):
    return f"FUGA: {a}"

print(hoge('hello'))

# 2024-02-01 11:10:51 INFO  [stopwatch.stopwatch:11] (1) ENTER hoge
# 2024-02-01 11:10:51 INFO  [stopwatch.stopwatch:11] (2) ENTER fuga
# 2024-02-01 11:10:51 INFO  [stopwatch.stopwatch:19] (2) LEAVE fuga (took:  0.000001 usec)
# 2024-02-01 11:10:51 INFO  [stopwatch.stopwatch:19] (1) LEAVE hoge (took:  0.000063 usec)
# HOGE: FUGA: hello