진행 중인 학교 프로젝트 중 API 호출이나 DB 상호작용 등에 있어서 로그를 남기면 좋겠다고 생각했습니다.
프로젝트를 본격적으로 시작하기 전 파이썬에 대해 공부를 할 때 봤던 데코레이터가 생각이 나서 이걸 활용해서 로깅 체계를 구축해 보면 좋지 않을까 해서 다시 한번 데코레이터에 대해 학습하고 직접 적용해 보는 시간을 가졌습니다.
# 00. Decorator?
파이썬의 데코레이터를 알아가기 전에 decorator의 사전적 의미를 먼저 살펴보겠습니다.
- 1.실내 장식자
- 2.장식하는 사람
- 3.칠·도배업자
장식하다, 꾸미다의 의미를 가진 동사 decorate에 행위자 접미사를 붙인 파생 명사입니다.
공통적으로 무언가를 장식하는 행위의 주체자의 의미를 가진 것으로 보아, 코드상 존재하는 기존의 무언가를 꾸미는 행위를 하는 역할이라고 추측할 수 있습니다.
사용하고 있는 함수에 기능을 추가하고 싶은데, 기존 코드는 수정하지 않고자 할 때가 있고요,
그리고 또 여러 함수에 공통적인 추가 기능을 부여하고자 할 때도 있습니다.
이 추가적인 기능을 '꾸민다'라는 의미로 치환하고 데코레이터가 기존 함수의 동작을 확장하여 꾸며준다고 이해하면 좋을 듯합니다.
조금 더 구체적으로 말로 풀자면, 데코레이터는 하나의 함수를 취해 또 다른 함수를 반환하는 함수입니다.
# 01. Decorator가 왜 필요할까?
데코레이터의 등장 이전 기존의 코드에 기능을 추가하는 방식을 PEP(Python Enhancement Proposals)에서 제공하는 예시로 확인해 보겠습니다.
def foo(self):
perform_method_operation
foo = classmethod(foo)기존 foo 함수를 클래스 메서드로 정의하는 추가 기능을 붙인 코드입니다.
이 코드는 명확한 문제점이 있습니다.
함수의 본문 끝까지 전부 읽고, foo = classmethod(foo) 라인까지 읽어야 비로소 "이 함수는 클래스 메서드다"라는 사실을 알 수 있게 됩니다.
만약, 대규모/장문 함수에서는 함수의 핵심 행위와 추가기능 선언 부분이 떨어져 있어 가독성이 크게 떨어질 수 있습니다.
def foo(cls):
pass
foo = synchronized(lock)(foo)
foo = classmethod(foo)또한 추가 기능을 여러 개 확장한다고 할 때, 같은 함수의 이름을 여러 번 반복해서 사용해야 하는 문제점도 있습니다.
이는 코드 변경/리팩토링 시 오타 가능성을 높이고, 코드를 읽기에도 불필요한 주의를 끌게 됩니다.
이러한 문제점들을 해결하는 방식이 바로 데코레이터입니다.
# 02. 데코레이터의 문법
지금부터는 데코레이터를 직접 작성하고 사용하는 방법에 대해 알아보겠습니다.
기본 문법
def decorator(func):
def wrapper():
print("before")
func()
print("after")
return wrapper
@decorator
def method():
print("run method")
method()
# 출력 :
# before
# run method
# after
기본적으로는 함수를 매개변수로 받는 데코레이터 함수 내에 래퍼 함수를 씌우는 것으로 구현합니다.
이렇게 구현한 데코레이터는 데코레이터를 붙이고자 하는 함수 선언부 이전에 @데코레이터_이름을 작성하여 사용하실 수 있습니다.
자바의 애너테이션과 사용법과 모양새가 비슷한데요, 데코레이터는 기능을 확장하는 것과 다르게, 자바의 애너테이션은 주석(comment)과 같이 프로그래밍 언어 자체에 영향을 미치지 않으면서 다른 프로그램에게 유용한 정보를 제공한다는 점에서 차이가 있습니다.
데코레이터에 매개변수 받기
def repeat(n):
def decorator(func):
def wrapper():
for _ in range(n):
func()
return wrapper
return decorator
@repeat(3)
def say_hi():
print("Hi!")
say_hi()
# 출력 :
# Hi!
# Hi!
# Hi!
외부 팩토리 함수에서 인자를 받는 것으로, 데코레이터 로직 내에서 인자를 활용할 수 있습니다.
위 코드는 데코레이터에서 반복 횟수를 인자로 받아, 원본 함수를 반복하는 동작을 수행합니다.
데코레이터 여러 개 지정
def uppercase(func):
def wrapper(*args, **kwargs):
return func(*args, **kwargs).upper()
return wrapper
def exclaim(func):
def wrapper(*args, **kwargs):
return func(*args, **kwargs) + "!"
return wrapper
@exclaim
@uppercase
def shout(text):
return text
print(shout("hello")) # 출력 : HELLO!
하나의 함수에 여러 개의 데코레이터를 지정할 수도 있습니다.
데코레이터를 여러 개 쌓으면, 내부적으로는 함수가 합성이 됩니다.
위 코드의 경우는 곧 shout = exclaim( uppercase(shout) )과 같은 형태로 합성되는데, 이로 인해 데코레이터 적용 순서의 경우 가장 안쪽 함수(함수 바로 위)부터 적용이 됩니다.
즉, 대문자로 바꾸고 나서 "!"를 붙여준다고 이해하시면 되겠습니다.
데코레이터 중복 지정
def tag(name):
def decorator(func):
def wrapper(*args, **kwargs):
return f"<{name}>{func(*args, **kwargs)}</{name}>"
return wrapper
return decorator
@tag("b")
@tag("i")
def formatted(text):
return text
print(formatted("bold+italic"))
# 출력: <b><i>bold+italic</i></b>
동일한 데코레이터를 여러 번 중첩 적용할 수 있습니다.
위에서 설명드린 바와 같이 함수 바로 위 데코레이터 (@tag("i"))부터 순서대로 적용이 됩니다.
# 03. 데코레이터로 로깅하기
이렇게 정리한 데코레이터 개념을 활용하여 프로젝트에서 로깅 기능을 구현했습니다.
로깅 데코레이터를 총 세 개 정의했고요 일반 함수, API 라우터 함수, 데이터베이스 작업 함수에 각각 붙일 수 있는 데코레이터를 작업했습니다.
그중 API 라우터 함수에 붙이는 용도로 작성한 데코레이터 함수 코드를 보여드리겠습니다.
# API 엔드포인트용 데코레이터
def log_api_call(func: Callable) -> Callable:
"""API 엔드포인트의 호출을 로깅합니다."""
@functools.wraps(func)
async def async_wrapper(*args, **kwargs):
start_time = time.time()
logger = logging.getLogger(f"api.{func.__name__}")
# 요청 정보 추출
request_info = {}
for arg in args:
if isinstance(arg, Request):
request_info = {
"method": arg.method,
"url": str(arg.url),
"client_ip": arg.client.host if arg.client else None,
"user_agent": arg.headers.get("user-agent", "")
}
break
# 요청 시작 로깅
api_path = request_info.get("url", "").split("?")[0] if request_info else ""
method = request_info.get("method", "") if request_info else ""
logger.info(f"API 호출 시작: {method} {api_path} ({func.__name__})", extra={
"extra_data": {
"event": "api_call_start",
"function": func.__name__,
"request_info": request_info,
"args_count": len(args),
"kwargs_keys": list(kwargs.keys())
}
})
try:
# 함수 실행
if asyncio.iscoroutinefunction(func):
result = await func(*args, **kwargs)
else:
result = func(*args, **kwargs)
execution_time = time.time() - start_time
# 성공 로깅
logger.info(f"API 호출 성공: {method} {api_path} ({func.__name__})", extra={
"extra_data": {
"event": "api_call_success",
"function": func.__name__,
"execution_time": round(execution_time, 3),
"result_type": type(result).__name__
}
})
return result
except Exception as e:
execution_time = time.time() - start_time
# 에러 로깅
logger.error("API 호출 실패", extra={
"extra_data": {
"event": "api_call_error",
"function": func.__name__,
"execution_time": round(execution_time, 3),
"error_type": type(e).__name__,
"error_message": str(e),
"traceback": traceback.format_exc()
}
})
raise
@functools.wraps(func)
def sync_wrapper(*args, **kwargs):
start_time = time.time()
logger = logging.getLogger(f"api.{func.__name__}")
# 요청 정보 추출
logger.info(f"API 호출 시작: {func.__name__}", extra={
"extra_data": {
"event": "api_call_start",
"function": func.__name__,
"args_count": len(args),
"kwargs_keys": list(kwargs.keys())
}
})
try:
result = func(*args, **kwargs)
execution_time = time.time() - start_time
# 성공 로깅
logger.info(f"API 호출 성공: {func.__name__}", extra={
"extra_data": {
"event": "api_call_success",
"function": func.__name__,
"execution_time": round(execution_time, 3),
"result_type": type(result).__name__
}
})
return result
except Exception as e:
execution_time = time.time() - start_time
# 에러 로깅
logger.error("API 호출 실패", extra={
"extra_data": {
"event": "api_call_error",
"function": func.__name__,
"execution_time": round(execution_time, 3),
"error_type": type(e).__name__,
"error_message": str(e),
"traceback": traceback.format_exc()
}
})
raise
# async 함수인지 확인
import asyncio
if asyncio.iscoroutinefunction(func):
return async_wrapper
else:
return sync_wrapper
기본적으로 sync 함수와 async 함수 둘 다 붙일 수 있는 데코레이터이기 때문에, 이를 판별하고 종류에 맞는 wrapper 함수를 실행하도록 합니다.
데코레이터 로직이 동작 시작하면, 그 시점의 시간을 기록하고, try 문 내에서 이를 기록하여 API의 총 실행 시간을 기록합니다.
또한, except문 내에서도 로깅하는 동작을 정의하여, 예외가 발생한 경우에도 발생한 예외에 대해 로깅이 가능하도록 구현했습니다.
콘솔에 출력하는 로그는 아래와 같습니다.
제가 최근에 학교에서 기업이랑 연결해 주는 인턴 과정에 총 세 번 지원했는데, 세 번 연달아 서류에서 탈락했습니다.
지금 네 번째 지원 넣고 결과 기다리는 중인데... 기분이 화가 나다가 우울하다가 짜증이 나다가 그러더라고요.
그리고 어제 함께 공부했던 몇 분들과 오랜만에 온라인에서 얘기 나눌 기회가 있었는데, 취업하신 분, 아직 준비 중이신 분 할 것 없이 다들 최소 지원을 100군데 이상은 했다고 하시더라고요.
그 얘기 듣고 생각이 들었습니다. '아 지금 내가 느끼고 있는 감정이 되게 쓸모가 없는 거였구나...'
앞으로 수십 번 이상 탈락 통보를 받을 수 있을 텐데 고작 몇 군데 지원해보고 감정에 일희일비하면 안 되겠다고 느꼈습니다.
탈락했으면 탈락한 이유가 있는 거고, 부족한 점 채워서 꾸준히 스스로를 업데이트해야겠죠.