프로파일링 (2) - 함수 실행 시간 계산하기

프로파일링 (1) - 줄리아 집합 (Julia set)

---

지난 포스트에서는 time 라이브러리와 print 함수를 이용해 함수 시작과 끝에서 시각을 측정하는 방식으로 계산했습니다. 하지만 실행 시간은 네트워크, 디스크, RAM 접근하는 시간 및 환경에 따라 편차가 발생하며, 반복 측정하면 정규 분포가 나와야 합니다. (저는 구글 colab pro Jupyter 노트북을 이용했습니다)

 

데코레이터

print 문 기반 시간 측정은 간단하지만 코드가 금방 더렵해지고 모든 함수 내부에 일일해 print 문을 선언해줘야 하는 귀찮음이 발생합니다. 따라서 시간을 측정하려는 함수 위에 데코레이터를 추가하는 방식으로 조금 더 깔끔하게 구현할 수 있습니다.

다음 코드를 보면 timefn 이라는 데코레이터는 내부에 measure_time 함수를 정의하여 실제 실행하는 (장식할 대상) 함수를 전달합니다. measure_time 함수 안에서 fn 함수를 호출하는 부분은 time.time() 안으로 감싸서 시간을 구하고 출력합니다. 또한, 실제 실행하는 함수 이름을 출력하기 위해 functools.wraps 를 사용해서 데코레이터로 넘어온 함수 이름과 독스트링을 호출하도록 합니다. (functools.wraps 를 사용하지 않으면 데코레이터 함수 그 자체의 이름이 출력됩니다)

from functools import wraps

def timefn(fn):
    @wraps(fn)
    def measure_time(*args, **kwargs):
        t1 = time.time()
        result = fn(*args, **kwargs)
        t2 = time.time()
        print(f'{fn.__name__} took {t2-t2} seconds')
        return result
    return measure_time   
 
@timefn
def calculate_julia(desired_width=1000, maxiter=300):

>>> output = calculate_julia()
Total elements: 1000000
calculate_z  took 9.735063314437866 seconds
calculate_julia took 10.280469417572021 seconds

 

timeit

timeit 모듈을 사용해서 CPU를 집중적으로 사용하는 함수의 실행 속도를 측정할 수 있습니다. 쥬피터 노트북에서는 다음 명령어로 측정할 수 있으며, 오랫동안 실행하는 함수르면 -r -n 의 인자값을 조절합니다. 반복 횟수의 결과 중에서 가장 좋은 결과를 보여주며 -r -n 을 따로 주지 않았을 경우 코랩에서는 r=5, n=1 로 반복 수행합니다. -v (verbose) 옵션을 켜면 반복할 때마다 루프의 누적 시간을 표시해줍니다.

보통 반복 횟수를 늘리면 결과가 거의 일정 값으로 수렴하며, 반복할 때마다 발생하는 편차는 "zs/cs" 와 같은 리스트를 생성하는 데서 발생하게 되고 백그라운드에서 실행 중인 다양한 작업이 무작위로 영향을 주기도 합니다.

%timeit -n {반복 횟수} -r {반복당 시간 측정 횟수} calculate_julia() 
1 loop, best of 5: 10.2 s per loop

 

만약 리눅스 환경이나 shell script 에서 사용하려면 다음 명령어를 이용해 줄 수 있습니다. 지난 포스트에서 구현된 함수가 julia.py 이고 속도를 측정하려는 함수 "calculate_julia"가 julia 모듈 안에 정의되어 있으므로 -s 옵션을 사용해서 그 모듈을 임포트 해야합니다.

python -m timeit -n 5 -r 1 -s "import julia" "julia.calculate_julia()"

 

---

프로파일링 (3) - cProfile 모듈

프로파일링 (4) - line_profiler

프로파일링 (5) - 바이트코드: 내부작동 이해하기