Profiler Example (GNU Octave (version 5.2.0))

아래는 짧막한 성능 분석기 작업 예시입니다. 성능 분석기 함수에 대한 자세한 문서는 성능 분석을 보십시오.

global N A;

N = 300;
A = rand (N, N);

function xt = timesteps (steps, x0, expM)
  global N;

  if (steps == 0)
    xt = NA (N, 0);
  else
    xt = NA (N, steps);
    x1 = expM * x0;
    xt(:, 1) = x1;
    xt(:, 2 : end) = timesteps (steps - 1, x1, expM);
  endif
endfunction

function foo ()
  global N A;

  initial = @(x) sin (x);
  x0 = (initial (linspace (0, 2 * pi, N)))';

  expA = expm (A);
  xt = timesteps (100, x0, expA);
endfunction

function fib = bar (N)
  if (N <= 2)
    fib = 1;
  else
    fib = bar (N - 1) + bar (N - 2);
  endif
endfunction

tic; foo; toc;
⇒ Elapsed time is 2.37338 seconds.

tic; bar (20); toc;
⇒ Elapsed time is 2.04952 seconds.

그러나 위 결과는 어디에서 시간이 걸렸는지에 대하여 많은 정보를 주지 않습니다. 예를 들어 expm를 단독으로 호출하면, 본 함수가 시간 단계를 더 많이 먹고, 재귀까지 합니다. 더 자세한 정보를 얻으려면, 성능 분석기 써야 합니다.

profile on;
foo;
profile off;

data = profile ("info");
profshow (data, 10);

   #  Function Attr     Time (s)        Calls
---------------------------------------------
   7      expm             1.034            1
   3  binary *             0.823          117
  41  binary \             0.188            1
  38  binary ^             0.126            2
  43 timesteps    R        0.111          101
  44        NA             0.029          101
  39  binary +             0.024            8
  34      norm             0.011            1
  40  binary -             0.004          101
  33   balance             0.003            1

각 항목은 실행한 적이 있는 개별 함수(가장 오래 걸린 10개만)와 그 각각에 대한 얼마간의 정보입니다. ‘binary *’ 꼴의 항목은 이항 연산자이고, 나머지 항목은 일반적인 함수입니다. 내장인 expm 따위와 자작한 굳은 절차(예: timesteps)도 항목에 있습니다. 이 성능 분석에서는 expm이 처리 시간을 가장 많이 차지하면서 한 번만 호출되었음을 바로 알 수 있습니다. 두 번째로 오래 걸린 명령은 굳은 절차인 timesteps에 있는 행렬 벡터 생성입니다.⁶

걸린 시간만 이 성능 분석에서 얻을 수 있는 정보가 아닙니다. 속성 열이 timesteps가 재귀 호출되었음을 보여줍니다. 너무나도 재귀 호출 여부가 명확한 이 예시에서는 그리 주목할 만한 것은 아니지만, 훨씬 복잡한 일을 할 때는 도움이 됩니다. 때문에 출력에 ‘binary \’이 있는 까닭도 쉽게 알 수 있습니다. data가 기록란 FunctionTable을 가진 구조체 배열(구조체 배열)임에 유의하십시오. 이 기록란이 성능 분석이 제공하는 미가공 자료를 포함합니다. 표의 첫 번째 열에 있는 번호는 해당 함수를 찾는 색인을 제공합니다. data.FunctionTable(41)을 보면 아래와 같은 정보가 있습니다.

  scalar structure containing the fields:

    FunctionName = binary \
    TotalTime =  0.18765
    NumCalls =  1
    IsRecursive = 0
    Parents =  7
    Children = [](1x0)

표에 정보가 있고, Parents와 Children 기록란이 추가로 있습니다. 이 둘은 모두 해당 란에 기록된 함수가 이 함수를 직접 호출하였는지(이 예시에서 7은 expm임) 또는 재귀 여부(재귀이면 빈 란)를 포함한 배열입니다. 그러므로 \ 연산자는 expm가 내부에서 사용한 것입니다.

이제 bar를 봅시다. 성능 분석 작업을 아주 새로 시작하여야 합니다.(기존 자료를 지우고, 성능 분석기를 다시 시작하는 profile on으로 합니다.)

profile on;
bar (20);
profile off;

profshow (profile ("info"));

   #            Function Attr     Time (s)        Calls
-------------------------------------------------------
   1                 bar    R        2.091        13529
   2           binary <=             0.062        13529
   3            binary -             0.042        13528
   4            binary +             0.023         6764
   5             profile             0.000            1
   8               false             0.000            1
   6              nargin             0.000            1
   7           binary !=             0.000            1
   9 __profiler_enable__             0.000            1

당연히 bar도 재귀입니다. 거추장스럽게 bar 혼자서 대부분의 시간을 잡아먹으면서 피보나치 수를 13,529번이나 재귀하여서 계산합니다.

마지막으로 foo와 bar를 같이 성능 분석하고 싶다고 칩시다. 이미 bar에 대한 실행 시간 자료를 모았기 때문에, 기존 자료를 지우지 않고 성능 분석기를 다시 시작하여 foo에 댜한 없는 자료를 모으면 됩니다. 아래와 같이 합니다.

profile resume;
foo;
profile off;

profshow (profile ("info"), 10);

아래 표에 보이듯이 두 함수에 대한 성능 분석이 함께 섞였습니다.

   #  Function Attr     Time (s)        Calls
---------------------------------------------
   1       bar    R        2.091        13529
  16      expm             1.122            1
  12  binary *             0.798          117
  46  binary \             0.185            1
  45  binary ^             0.124            2
  48 timesteps    R        0.115          101
   2 binary <=             0.062        13529
   3  binary -             0.045        13629
   4  binary +             0.041         6772
  49        NA             0.036          101

각주

(6)

연산자가 단지 이항 곱셈 연산자인 것 밖에 알 수 없으나, 이항 곱셈 연산자가 다행히도 부호의 한 곳에만 있어서 행렬 벡터 생성이 오래 걸린다는 점을 압니다. 이항 곱셈 연산자가 여러 곳에 있었으면, 이 예시에서는 다루지 않았으나, 계층 성능 분석을 사용하여 연산자가 실행되며 시간을 보낸 위치를 찾을 수 밖에 없습니다.

13.7 성능 분석 예시

각주

(6)