파이썬 - 데코레이터 (Decorator)

이번 강좌에서는 전 강좌에서 예고한 대로 데코레이터(Decorator)에 대해서 알아 보겠습니다. 이 강좌를 이해하시기 위해서는 퍼스트 클래스 함수와 클로저를 이해하고 계셔야 합니다. 만약 이해하고 계시지 않으시다면 밑의 강좌를 참고하여 주십시오.

파이썬 - 퍼스트클래스 함수 (First Class Function)
파이썬 - 클로저 (Closure)

데코레이터란 무엇일까요? 사전적 의미로는 "장식가" 또는 "인테리어 디자이너" 등의 의미를 가지고 있습니다. 이름 그대로, 자신의 방을 예쁜 벽지나 커튼으로 장식을 하듯이, 기존의 코드에 여러가지 기능을 추가하는 파이썬 구문이라고 생각하시면 됩니다. 많은 파이썬 초보자들이 데코레이터를 이해하는데 어려움을 겪습니다. 그런데 데코레이터란 그렇게 어려운 개념이 아니니 걱정하지 마십시오. 그럼 이제부터 예제를 보면서 데코레이터의 사용법을 배워보죠.

먼저 원하시는 디렉터리안에 decorator.py 라는 파이썬 파일을 만들고 밑의 코드를 저장하여 주십시오.

decorator.py
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

지난 강좌인 파이썬 - 클로저 (Closure)을 읽으셨다면 위의 코드를 이해하고 계실겁니다.  데코레이터 코드도 위의 코드와 아주 비슷합니다. 다만 함수를 다른 함수의 인자로 전달한다는 점이 조금 틀립니다. 가장 간단한 데코레이터 예제를 보겠습니다. 다음의 코드를 저장하고 실행하여 주십시오.

decorator.py
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) 함수를 이용하여 여러가지 기능을 추가할 수가 있기 때문입니다. 예제를 볼까요?

decorator.py
# -*- coding: utf-8 -*-
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와 같은 구문은 잘 사용하지 않고, "@" 심볼과 데코레이터 함수의 이름을 붙여 쓰는 간단한 구문을 사용합니다. 위의 코드는 다음의 코드와 같이 간소화할 수가 있습니다.
decorator.py
# -*- coding: utf-8 -*-
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 함수와 같이 인수를 가진 함수를 데코레이팅하고 싶을 때는 어떻게 할까요? 파일을 수정하고 실행을 해보죠.
decorator.py
# -*- coding: utf-8 -*-
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 20, in 
    display_info('John', 25)  #4
TypeError: wrapper_function() takes no arguments (2 given)

wrapper_function은 인자를 받지 않는데 2개의 인자가 전달되었다는 타입에러가 발생했습니다. 다음과 같이 코드를 수정하면 문제가 해결됩니다.

decorator.py
# -*- coding: utf-8 -*-
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에 인수를 추가하여 문제를 해결하였습니다.

데코레이터는 이런 함수 형식 말고도 클래스 형식을 사용할 수도 있습니다. 한번 구경해 볼까요?

decorator.py
# -*- coding: utf-8 -*-
# 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)하기 위해서 많이 사용됩니다. 또한 프로그램의 성능을 테스트하기 위해서도 많이 쓰입니다. 리눅스나 유닉스 서버 관리자는 스크립트가 실행되는 시간을 측정하기 위해서 다음과 같은 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

데코레이터를 이용하여 위와 같은 로깅 기능을 만들 수가 있는데, 한 번 만들어 볼까요?

decorator.py
# -*- coding: utf-8 -*-
import datetime
import time


def my_logger(original_function):
    import logging
    logging.basicConfig(filename='{}.log'.format(original_function.__name__), 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)

display_info('John', 25)

위의 코드를 실행하면, 터미널에 다음과 같이 출력되고 'decorator.py' 파이썬 파일이 저장된 디렉터리에 'display_info.log'라는 이름의 로그 파일이 생성될 겁니다. 프로그램을 실행해주십시오.

$ python decorator.py
display_info(John, 25) 함수가 실행됐습니다.

로그 파일안에는 다음과 같은 정보가 기록된 것을 볼 수 있습니다.

display_info.log
INFO:root:[2016-09-08 08:02] 실행결과 args - ('John', 25), kwargs - {}

이번에는 다른 데코레이터를 하나 더 추가해서 프로그램이 실행되는 시간을 재 볼까요?

decorator.py
# -*- coding: utf-8 -*-
import datetime
import time


def my_logger(original_function):
    import logging
    logging.basicConfig(filename='{}.log'.format(original_function.__name__), 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, 두 개의 데코레이터를 동시에 사용해 보도록하죠.

decorator.py
# -*- coding: utf-8 -*-
import datetime
import time


def my_logger(original_function):
    import logging
    logging.basicConfig(filename='{}.log'.format(original_function.__name__), 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 초
display_info.log
INFO:root:[2016-09-08 08:02] 실행결과 args - ('John', 25), kwargs - {}

#1, #2에 데코레이터 2개를 한꺼번에 사용하였습니다. 터미널 상의 실행결과는 아까와 같이 출력되었습니다. 그런데 로그 파일에 아무것도 기록이 안됐습니다. 그 대신에 wrapper.log란 이름의 로그 파일 생성됐고, 그 안에 다음과 같은 로그가 남았습니다.

wrapper.log
INFO:root:[2016-09-08 08:05] 실행결과 args - ('John', 25), kwargs - {}

흠... 왜 그럴까요? 그럼 이번에는 데코레이터의 순서를 바꿔 볼까요?

decorator.py
# -*- coding: utf-8 -*-
import datetime
import time


def my_logger(original_function):
    import logging
    logging.basicConfig(filename='{}.log'.format(original_function.__name__), 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  #3


def my_timer(original_function):  #4
    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
@my_logger  #1
def display_info(name, age):
    time.sleep(1)
    print 'display_info({}, {}) 함수가 실행됐습니다.'.format(name, age)

display_info('John', 25)
display_info.log
INFO:root:[2016-09-08 08:02] 실행결과 args - ('John', 25), kwargs - {}
INFO:root:[2016-09-08 08:07] 실행결과 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 함수를 인자로써 리턴하기 때문에 생기는 현상입니다. #4에서 original_function은 물론 wrapper 함수와 같습니다.

위와 같은 현상을 방지하기 위해서 만들어진 모듈이 있는데 그것이 functools 모듈의 wraps 데코레이터입니다. 한 번 사용해 볼까요?

decorator.py
# -*- coding: utf-8 -*-
from functools import wraps
import datetime
import time


def my_logger(original_function):
    import logging
    logging.basicConfig(filename='{}.log'.format(original_function.__name__), 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.01256990433 초/pre>

display_info.log
INFO:root:[2016-09-08 08:02] 실행결과 args - ('John', 25), kwargs - {}
INFO:root:[2016-09-08 08:07] 실행결과 args - ('John', 25), kwargs - {}
INFO:root:[2016-09-08 08:12] 실행결과 args - ('Jimmy', 30), kwargs - {}

우리가 원하는 결과가 아무 문제 없이 터미널과 로그 파일에 출력되었습니다.

이제 데코레이터의 사용법을 마스터했다고 해도 과언이 아닙니다. 별거 없죠? ㅎ 이해는 했지만 실제 사용을 하지 않으면 잊어 버리니, 연습을 많이 하시고 실제 프로젝트에서도 활용해 보시기 바랍니다.

다음 파이썬 강좌에서는 제너레이터(Generator)에 대해서 알아겠습니다.


blog comments powered by Disqus