[Python] 프로파일링으로 병목 찾기 (line_profiler)

 자신이 작성한 코드가 오래 걸린다 싶을 때 어느 부분에서 병목이 생기는지 알 수 있는 방법을 소개하려고 합니다.

 

0. 코드

 다음 코드는 '줄리아 집합'을 생성하는 코드입니다.

 

import numpy as np

@profile
def julia_set(width, height, c, max_iter):
    x_min, x_max = -2.0, 2.0
    y_min, y_max = -2.0, 2.0

    x_range = np.linspace(x_min, x_max, width)
    y_range = np.linspace(y_min, y_max, height)

    img = np.empty((width, height))

    for x in range(width):
        for y in range(height):
            zx, zy = x_range[x], y_range[y]
            count = 0

            while abs(zx * zx + zy * zy) < 4.0 and count < max_iter:
                z_next = zx * zx - zy * zy + c.real
                zy, zx = 2.0 * zx * zy + c.imag, z_next

                count += 1

            img[x, y] = count

    return img


if __name__ == "__main__":
    width = 1000
    height = 1000
    c = complex(-0.7, 0.27015)
    max_iter = 1024
    julia_img = julia_set(width, height, c, max_iter)

 

 위 코드를 실행하게 되면 다음과 같이 프랙탈을 생성하게 됩니다.

 

plt.imshow(julia_img.T, cmap='inferno', extent=(-2, 2, -2, 2))
plt.colorbar()
plt.title(f'Julia Set for c = {c}')
plt.xlabel('Real')
plt.ylabel('Imaginary')
plt.show()

1. line_profiler

 이제 line_profiler를 사용하여 코드 어느 부분에서 병목이 생기는지 알아보겠습니다. line_profiler는 코드를 한 줄씩 프로파일함으로써 CPU 병목 원인을 찾아줍니다. @profile 데커레이터로 사용하여 프로파일 할 함수를 표시하고 kernprof 스크립트로 코드를 실행합니다.

- l 옵션은 한줄씩 프로파일 하겠다는 옵션

- v 옵션은 출력 결과를 자세하게 보여주는 옵션

$ kernprof -l -v julia_set.py
...
Total time: 52.0934 s
File: julia_set.py
Function: julia_set at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           @profile
     5                                           def julia_set(width, height, c, max_iter):
     6         1          0.5      0.5      0.0      x_min, x_max = -2.0, 2.0
     7         1          0.3      0.3      0.0      y_min, y_max = -2.0, 2.0
     8
     9         1        114.9    114.9      0.0      x_range = np.linspace(x_min, x_max, width)
    10         1         42.3     42.3      0.0      y_range = np.linspace(y_min, y_max, height)
    11
    12         1         11.5     11.5      0.0      img = np.empty((width, height))
    13
    14      1001        186.5      0.2      0.0      for x in range(width):
    15   1001000     192188.1      0.2      0.4          for y in range(height):
    16   1000000     394653.7      0.4      0.8              zx, zy = x_range[x], y_range[y]
    17   1000000     182605.6      0.2      0.4              count = 0
    18
    19  31342631   15770389.1      0.5     30.3              while abs(zx * zx + zy * zy) < 4.0 and count < max_iter:
    20  30342631   14756371.1      0.5     28.3                  z_next = zx * zx - zy * zy + c.real
    21  30342631   13512845.7      0.4     25.9                  zy, zx = 2.0 * zx * zy + c.imag, z_next
    22
    23  30342631    6923298.2      0.2     13.3                  count += 1
    24
    25   1000000     360678.8      0.4      0.7              img[x, y] = count
    26
    27         1          0.4      0.4      0.0      return img

 

 

 실행 결과 총 52.0934초가 걸렸고 19번째 줄을 31,342,631회 실행함으로써 전체 실행 시간의 30.3%를 차지하는 것을 볼 수 있습니다. 뿐만 아니라 루프 안에서의 연산도 꽤 걸리는 걸 보아 while 조건을 개선하면 시간을 줄일 수 있을 것 같습니다. 그렇다면 조건문이 각각 얼마나 걸리는지 %timeit을 사용하여 확인해 보겠습니다.

 

zx = -1.9949937421777222
zy = -0.1376720901126407
count = 0
max_iter= 256

%timeit abs(zx * zx + zy * zy) < 4.0
# 80.7 ns ± 1.59 ns per loop (mean ± std. dev. of 7 runs, 10,000,000 loops each)

%timeit count < max_iter
# 23.2 ns ± 1.59 ns per loop (mean ± std. dev. of 7 runs, 10,000,000 loops each)

 

count를 검사하는 코드가 abs를 호출하는 코드보다 두 배 이상 빠른 것을 알 수 있습니다.

여기서 'while 문의 연산 순서를 바꿔서 속도 개선을 할 수 있다.'는 가설을 세울 수 있습니다.

 

$ kernprof -l -v julia_set.py
...
Total time: 46.4017 s
File: julia_set.py
Function: julia_set at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           @profile
     5                                           def julia_set(width, height, c, max_iter):
     6         1          0.4      0.4      0.0      x_min, x_max = -2.0, 2.0
     7         1          0.2      0.2      0.0      y_min, y_max = -2.0, 2.0
     8
     9         1        101.3    101.3      0.0      x_range = np.linspace(x_min, x_max, width)
    10         1         39.0     39.0      0.0      y_range = np.linspace(y_min, y_max, height)
    11
    12         1          9.3      9.3      0.0      img = np.empty((width, height))
    13
    14      1001        180.2      0.2      0.0      for x in range(width):
    15   1001000     179847.7      0.2      0.4          for y in range(height):
    16   1000000     339211.8      0.3      0.7              zx, zy = x_range[x], y_range[y]
    17   1000000     168568.0      0.2      0.4              count = 0
    18
    19  31342631   14579008.0      0.5     31.4              while count < max_iter and abs(zx * zx + zy * zy) < 4.0:
    20  30342631   12911928.9      0.4     27.8                  z_next = zx * zx - zy * zy + c.real
    21  30342631   11979013.1      0.4     25.8                  zy, zx = 2.0 * zx * zy + c.imag, z_next
    22
    23  30342631    5892463.4      0.2     12.7                  count += 1
    24
    25   1000000     351339.6      0.4      0.8              img[x, y] = count
    26
    27         1          0.4      0.4      0.0      return img

 

조건문의 순서를 바꿔 실행한 결과 4초 정도 준 것을 확인할 수 있습니다.

 

line_profiler는 루프나 함수 내부의 각 라인이 비용을 얼마나 사용하는지 잘 알려줍니다. 프로파일 시 속도는 느려지지만 이런 정보는 개발자에게는 도움을 줍니다. 또한 프로파일 시 대표성 있는 데이터를 사용해야 하는 점도 유의해야 합니다.