ナード戦隊データマン

データサイエンスを用いて悪と戦うぞ

perfでプロファイリングして実行速度を改善する

ユニットテストでは、単に入力に対して正しい出力が得られるかに焦点が当てられます。しかし、実行速度が問題になる場合はプロファイリングが必要です。ここでは、配列の合計を求めるという単純な関数を計測し、実行速度がどのように変わるのか見てみます。

準備

  1. perfをインストールします。
  2. 以下のbashスクリプトを作成します。
#!/bin/bash
perf stat -e cycles,stalled-cycles-frontend,stalled-cycles-backend,instructions,cache-references,cache-misses,branches,branch-misses,task-clock,faults,minor-faults,cs,migrations -r 3 python $1

最初の関数

まず、初心者的なコードを作成して、計測してみましょう。

def solvesum(arr):
    sum = 0
    for d in arr:
        sum = sum + d
    return sum

solvesum(range(1000000))

計測するために以下を実行します。

./perf.sh solvesum1.py > prof1.log 2>&1
 Performance counter stats for 'python solvesum1.py' (3 runs):

       299,359,812      cycles:u                  #    1.968 GHz                      ( +-  1.10% )  (48.42%)
        98,050,733      stalled-cycles-frontend:u #   32.75% frontend cycles idle     ( +-  4.10% )  (50.24%)
        47,570,221      stalled-cycles-backend:u  #   15.89% backend cycles idle      ( +-  8.98% )  (51.91%)
       599,155,349      instructions:u            #    2.00  insn per cycle         
                                                  #    0.16  stalled cycles per insn  ( +-  1.20% )  (64.25%)
         1,063,508      cache-references:u        #    6.992 M/sec                    ( +-  1.53% )  (64.48%)
            43,573      cache-misses:u            #    4.097 % of all cache refs      ( +-  8.70% )  (63.77%)
       121,408,246      branches:u                #  798.167 M/sec                    ( +-  0.85% )  (62.31%)
           992,437      branch-misses:u           #    0.82% of all branches          ( +- 15.66% )  (61.39%)
        152.108793      task-clock:u (msec)       #    0.997 CPUs utilized            ( +-  1.98% )
             1,102      faults:u                  #    0.007 M/sec                    ( +-  0.09% )
             1,102      minor-faults:u            #    0.007 M/sec                    ( +-  0.09% )
                 0      cs:u                      #    0.000 K/sec                  
                 0      migrations:u              #    0.000 K/sec                  

       0.152542791 seconds time elapsed                                          ( +-  1.94% )

この実行結果をベースに、速度を改善していきます。

ちょっと改善: +=を使う

sum = sum+dをsum+=dに変えるとどうなるのか見てみましょう。アセンブリレベルでは、キャッシュがより効率に利用されるはずです。

def solvesum(arr):
    sum = 0
    for d in arr:
        sum += d
    return sum

solvesum(range(1000000))
 Performance counter stats for 'python solvesum2.py' (3 runs):

       300,533,727      cycles:u                  #    1.956 GHz                      ( +-  2.23% )  (47.94%)
       101,197,145      stalled-cycles-frontend:u #   33.67% frontend cycles idle     ( +-  8.13% )  (49.12%)
        36,304,139      stalled-cycles-backend:u  #   12.08% backend cycles idle      ( +- 16.39% )  (51.78%)
       601,940,128      instructions:u            #    2.00  insn per cycle         
                                                  #    0.17  stalled cycles per insn  ( +-  1.38% )  (64.31%)
           959,623      cache-references:u        #    6.246 M/sec                    ( +-  5.96% )  (64.78%)
            53,203      cache-misses:u            #    5.544 % of all cache refs      ( +- 17.50% )  (64.33%)
       123,513,640      branches:u                #  803.881 M/sec                    ( +-  0.17% )  (63.43%)
         1,049,747      branch-misses:u           #    0.85% of all branches          ( +- 10.49% )  (61.71%)
        153.646763      task-clock:u (msec)       #    0.997 CPUs utilized            ( +-  2.92% )
             1,101      faults:u                  #    0.007 M/sec                    ( +-  0.08% )
             1,101      minor-faults:u            #    0.007 M/sec                    ( +-  0.08% )
                 0      cs:u                      #    0.000 K/sec                  
                 0      migrations:u              #    0.000 K/sec                  

       0.154173086 seconds time elapsed                                          ( +-  2.97% )

キャッシュの効率は上がりましたが、命令実行数が増え、分岐も増えていることがわかります。実行時間も増えてしまいました。

ビルトイン関数を用いる

ビルトイン関数はCやfortranなどによって最適化されているため、もっと高速になる可能性があります。

def solvesum(arr):
    return sum(arr)

solvesum(range(1000000))
 Performance counter stats for 'python solvesum3.py' (3 runs):

       159,695,368      cycles:u                  #    1.954 GHz                      ( +-  3.31% )  (48.15%)
        58,940,102      stalled-cycles-frontend:u #   36.91% frontend cycles idle     ( +- 12.01% )  (50.01%)
        35,743,688      stalled-cycles-backend:u  #   22.38% backend cycles idle      ( +- 10.19% )  (51.44%)
       268,115,136      instructions:u            #    1.68  insn per cycle         
                                                  #    0.22  stalled cycles per insn  ( +-  4.18% )  (65.86%)
           878,094      cache-references:u        #   10.744 M/sec                    ( +-  7.94% )  (66.29%)
            36,671      cache-misses:u            #    4.176 % of all cache refs      ( +-  4.29% )  (65.20%)
        61,061,060      branches:u                #  747.114 M/sec                    ( +-  1.72% )  (63.81%)
           803,359      branch-misses:u           #    1.32% of all branches          ( +-  4.20% )  (60.59%)
         81.729266      task-clock:u (msec)       #    0.993 CPUs utilized            ( +- 15.48% )
             1,102      faults:u                  #    0.013 M/sec                    ( +-  0.09% )
             1,102      minor-faults:u            #    0.013 M/sec                    ( +-  0.09% )
                 0      cs:u                      #    0.000 K/sec                  
                 0      migrations:u              #    0.000 K/sec                  

       0.082265436 seconds time elapsed                                          ( +- 15.35% )

キャッシュの効率も上がり、実行命令数や分岐数も減ったため、速度が改善されました。

numpyを使う

一般的に、numpyを使うと処理が速くなると言いますが、このような単純なケースでも同じことが言えるでしょうか。実際に試してみましょう。

import numpy as np
def solvesum(arr):
    return np.sum(arr)

solvesum(range(1000000))
 Performance counter stats for 'python solvesum4.py' (3 runs):

     1,017,890,789      cycles:u                  #    1.190 GHz                      ( +-  2.61% )  (48.86%)
     1,411,525,049      stalled-cycles-frontend:u #  138.67% frontend cycles idle     ( +-  0.94% )  (49.92%)
     1,227,192,211      stalled-cycles-backend:u  #  120.56% backend cycles idle      ( +-  1.61% )  (50.38%)
     1,355,742,429      instructions:u            #    1.33  insn per cycle         
                                                  #    1.04  stalled cycles per insn  ( +-  0.53% )  (63.25%)
         4,650,846      cache-references:u        #    5.437 M/sec                    ( +-  4.62% )  (63.87%)
           873,072      cache-misses:u            #   18.772 % of all cache refs      ( +-  4.20% )  (63.88%)
       326,591,077      branches:u                #  381.801 M/sec                    ( +-  0.37% )  (63.17%)
         3,419,062      branch-misses:u           #    1.05% of all branches          ( +-  0.83% )  (61.82%)
        855.395105      task-clock:u (msec)       #    1.677 CPUs utilized            ( +-  1.34% )
            28,753      faults:u                  #    0.034 M/sec                    ( +-  0.47% )
            28,736      minor-faults:u            #    0.034 M/sec                    ( +-  0.51% )
                 0      cs:u                      #    0.000 K/sec                  
                 0      migrations:u              #    0.000 K/sec                  

       0.509947783 seconds time elapsed                                          ( +-  7.85% )

あらら、遅くなってしまいました。numpyはあらゆるケースに対応するために条件分岐のコードが含まれている可能性があります。また、numpyの配列データの準備にも時間がかかります。もっと大きなデータで複雑な処理を行う場合は、numpyが役立つかもしれませんが、この場合は組込関数のほうが早いことがわかりました。

おわりに

速さの目標を立て、計測しながら関数を改善する工程はゲームに似ています。関数をレベルアップするために以下を考慮すると良いでしょう。

  • 組込関数が使える場合はそれを使う。
  • 複雑な演算では、numpyやblasを使って高速化されるか試す。
  • 余計なループや分岐がないか調べる。

ビルトイン関数やnumpy, blasなどは、一般的なプログラマが書くコードなんかよりもよほど巧妙に最適化されています。特段の理由がない限りライブラリを使ったほうがいいでしょう。