まんぼう日記

takataka's diary

Numpy / Theano で行列の積を高速に計算するには

computer 研究

オープンキャンパス，研究会出張，学科会議＋教授会，企業訪問，と続いた日々が昨日で一段落して，今日はだらだらと後始末（諸々の報告書作成）とか某誌編集委員の仕事とか．それもある程度片付いたので，ちょっとだけ研究．Pylearn2 の tutorial でお勉強 - 4時間目 - まんぼう日記 のつづきです．夏休みの自由研究としてはじめたのに，もう休み終わりや〜ん．

 

さて．Pylearn2 の tutorial にある convolutional net のサンプルを動かしたら遅くてCPUも効率的に使えてない様子だったので，その原因を追求しようと試みました．Pylearn2 は Theano を使い，Theano は Numpy を使い，Numpy は ATLAS，BLAS, LAPACK 等の数値計算ライブラリを使い，という関係になっているので，原因は

  1. Numpy が効率のよい数値計算ライブラリを呼び出せてない
  2. 1. は問題ないけど，Theano がおかしなことになっている
  3. 1. と 2. は問題なく，Pylearn2 がおかしなことになっている
  4. Pylearn2 も悪くなくて，マシンが遅いだけ

という4つのいずれかだと考えて，切り分けてみましょう．Pylearn2 のプログラムを解析して直接原因を探るのではないので，間接的に推測するだけですが．その過程で，「MacPorts で入れた Numpy で行列の積を高速に計算するにはどの variant がよい？」というのをちょこっと調べてみることにもなりました．

環境

以下の実験共通の条件というか計算機環境は次の通り．

  • iMac 27inch late 2012, Core i7 3.4GHz (Quad Core), メモリ 32GB
  • OS X 10.8 Mountain Lion
  • MacPorts を使用
  • Python は MacPorts で入れた 2.7 を使用

Numpy が効率のよい数値計算ライブラリを呼び出せてない？

MacPorts で入れた Numpy を使って行列の積を計算するプログラムを実行して，計算時間や，ちゃんとマルチスレッドで動いてるか，といったことを調べる実験を行います．

実験方法

以下のプログラムを動かして，行列の積に要するCPU時間を測定するとともに，「アクティビティモニタ」の表示を観察して，実行時のスレッド数やCPU使用率を目視で確認します．

import numpy as np
import time

N = 200
t_start = time.clock()
A = np.random.rand( N*N ).reshape( ( N, N ) )
B = np.random.rand( N*N ).reshape( ( N, N ) )
t_elapsed = time.clock() - t_start
print 'CPU time for initialization [sec] = ', t_elapsed

T = 10
t_start = time.clock()
for i in range( T ):
    C = np.dot( A, B )
t_elapsed = time.clock() - t_start
print 'N = ', N, 'T = ', T, 'average CPU time [sec] = ', t_elapsed / T

ただ，実際に動かしてみたら time.clock() の値は使えなさそう（マルチスレッドやから？）だと分かったので，次のように実行してみました．以下，上記のプログラムを hoge.py という名前のファイルに保存したとします．

$ time python -m cProfile hoge.py

timeコマンドで hoge.py 全体の実行時間を測るとともに，Python のプロファイラで関数呼び出し毎の時間も取得してみたということ．後者については

26.4. Python プロファイラ — Python 2.7ja1 documentation

に説明があります．

実験N1: MacPortsで入れた ATLAS を使う場合

使ったマシンの現状が

$ port installed atlas py27-numpy py27-scipy
  atlas @3.10.2_1+clang (active)
  py27-numpy @1.8.2_0+atlas+gcc48 (active)
  py27-scipy @0.14.0_0+atlas+gcc48 (active)

だったので，そのままで実験．Numpy がどんなライブラリを呼び出すように設定されているかは，次のようにして調べることができます．

$ python
>>> import numpy as np
>>> np.__config__.show()
atlas_threads_info:
    libraries = ['lapack', 'ptf77blas', 'ptcblas', 'tatlas']
    library_dirs = ['/opt/local/lib']
    define_macros = [('ATLAS_INFO', '"\\"3.10.2\\""')]
    language = f77
    include_dirs = ['/opt/local/include']
blas_opt_info:
    libraries = ['ptf77blas', 'ptcblas', 'tatlas']
    library_dirs = ['/opt/local/lib']
    define_macros = [('ATLAS_INFO', '"\\"3.10.2\\""')]
    language = c
    include_dirs = ['/opt/local/include']
atlas_blas_threads_info:
    libraries = ['ptf77blas', 'ptcblas', 'tatlas']
    library_dirs = ['/opt/local/lib']
    define_macros = [('ATLAS_INFO', '"\\"3.10.2\\""')]
    language = c
    include_dirs = ['/opt/local/include']
openblas_info:
  NOT AVAILABLE
lapack_opt_info:
    libraries = ['lapack', 'ptf77blas', 'ptcblas', 'tatlas']
    library_dirs = ['/opt/local/lib']
    define_macros = [('ATLAS_INFO', '"\\"3.10.2\\""')]
    language = f77
    include_dirs = ['/opt/local/include']
lapack_mkl_info:
  NOT AVAILABLE
blas_mkl_info:
  NOT AVAILABLE
mkl_info:
  NOT AVAILABLE

ちゃんとわかってませんが，上記を見るとMacPortsで入れたATLAS使うようになってそうです． 実行してみると…

$ time python -m cProfile hoge.py
N =  5000 CPU time for initialization [sec] =  0.490314
N =  5000 T =  10 average CPU time [sec] =  30.6721502  <== この値は参考になりません
10697 function calls (10598 primitive calls) in 41.132 seconds
   :
   1    0.092    0.092   41.133   41.133 hoge.py:2()
   2    0.490    0.245    0.490    0.245 {method 'rand' of 'mtrand.RandomState' objects}
   10   40.490    4.049   40.490    4.049 {numpy.core._dotblas.dot}

というわけで，5000 x 5000 の行列同士の積一回あたり4秒でした．また，アクティビティモニタで観察すると，スレッド数は9で，CPU使用率は800%近くになっていました．Quad Core の i7 だから論理コア数は8なので，800%ってのが全論理コアフル稼働状態のはず．

実験N2: Xcode付属の vecLib Framework を使う場合

上記の実験では特におかしな所は見当たりませんが，「MacPorts で入れた Atlas を使わへんかったらどうなんやろ，これより速いんか遅いんか」って気になったので，そっちも実験．Mac OS X では，Xcode の vecLib Framework の中に BLAS と LAPACK が含まれている（ vecLib Reference ）んですが，MacPorts で +atlas の variant つけずに Numpy & Scipy をインストールすると，そっちを使うみたいなので． 

 

py27-numpy と py27-scipy を sudo port -f deactivate してから，+atlas なしで install．

$ port installed py27-numpy py27-scipy
  py27-numpy @1.8.2_0 (active)
  py27-numpy @1.8.2_0+atlas+gcc48
  py27-scipy @0.14.0_0+atlas+gcc48
  py27-scipy @0.14.0_0+gcc48 (active)

で，

$ python
>>> import numpy as np
>>> np.__config__.show()
atlas_threads_info:
  NOT AVAILABLE
blas_opt_info:
    extra_link_args = ['-Wl,-framework', '-Wl,Accelerate']
    extra_compile_args = ['-msse3', '-I/System/Library/Frameworks/vecLib.framework/Headers']
    define_macros = [('NO_ATLAS_INFO', 3)]
atlas_blas_threads_info:
  NOT AVAILABLE
openblas_info:
  NOT AVAILABLE
lapack_opt_info:
    extra_link_args = ['-Wl,-framework', '-Wl,Accelerate']
    extra_compile_args = ['-msse3']
    define_macros = [('NO_ATLAS_INFO', 3)]
atlas_info:
  NOT AVAILABLE
lapack_mkl_info:
  NOT AVAILABLE
blas_mkl_info:
  NOT AVAILABLE
atlas_blas_info:
  NOT AVAILABLE
mkl_info:
  NOT AVAILABLE

となりました．この状態で実験N1と同じプログラムを実行してみると，

$ time python -m cProfile hoge.py
N = 5000 CPU time for initialization [sec] =  0.631823
N =  5000 T =  10 average CPU time [sec] =  11.2395173  <== この値は参考になりません
         10697 function calls (10598 primitive calls) in 30.880 seconds
        1    0.099    0.099   30.881   30.881 hoge.py:2()
        2    0.628    0.314    0.628    0.314 {method 'rand' of 'mtrand.RandomState' objects}
       10   30.095    3.010   30.095    3.010 {numpy.core._dotblas.dot}
real     0m30.960s
user     1m52.414s
sys     0m0.745s

実験N1で積一回あたり4秒やったのが3秒に．また，アクティビティモニタで観察すると，スレッド数は4で，CPU使用率は400%弱でした．

実験N1,N2の考察

というわけで，少なくともnp.dot()に関しては，

  • MacPorts で入れた Numpy は，ATLASやBLAS等を使ってちゃんとマルチスレッドで効率よく計算してくれる
  • MacPortsで入れた ATLAS を使うより，vecLib を使う方が速い

ようです．したがって，最初に書いた 1. から 4. までの可能性のうち，1. は否定できそうです．

Theano がおかしなことになっている？

次に，Theano がおかしなことをしている可能性を検討します．

実験方法

import numpy as np
import theano
import theano.tensor as T

A = T.dmatrix( 'A' )
B = T.dmatrix( 'B' )
AB = T.dot( A, B )
f = theano.function( [A, B], AB )

N = 10000
a = np.random.rand( N*N ).reshape( ( N, N ) )
b = np.random.rand( N*N ).reshape( ( N, N ) )

t_start = time.clock()
c = np.dot( a, b )
t_elapsed = time.clock() - t_start
print 'N = ', N, 'CPU time for np.dot() [sec] = ', t_elapsed

t_start = time.clock()
d = f( a, b )
t_elapsed = time.clock() - t_start
print 'N = ', N, 'CPU time for theano [sec] = ', t_elapsed

上記のプログラムを theano0905.py という名前のファイルに保存したとして，

$ time python theano0905.py

として結果を眺めてみます．上で述べたように time.clock() の値は信用できませんが，np.dot() と theano の f の場合の時間を比較できればよいので．

実験T1: MacPortsで入れた ATLAS を使う場合

実験N1と同じ条件での実験です．

$ time python theano0905.py
N =  10000 CPU time for np.dot() [sec] =  245.931655
N =  10000 CPU time for theano [sec] =  246.231735
real     1m8.628s
user     8m15.898s
sys     0m2.111s

Theano 経由でも np.dot() とほぼ同じ時間．アクティビティモニタで見ても，どっちの計算もスレッド数9, CPU使用率は800%弱でした．

実験T2: Xcode付属の vecLib Framework を使う場合

こちらは実験N2と同じ．

$ time python theano0905.py
N =  10000 CPU time for np.dot() [sec] =  92.035379
N =  10000 CPU time for theano [sec] =  92.663039
real     0m54.150s
user     3m9.805s
sys     0m1.343s

やはり np.dot() とTheano経由でほぼ同じ時間で，timeコマンドの出力（経過時間(real)）ではこちらの方が速いという結果．アクティビティモニタではスレッド数4, CPU使用率 400%弱．

実験T1,T2の考察

Theano は素直に Numpy を呼び出して効率良く計算できていると言えそうです．したがって，2. も否定できるようです．

Pylearn2 が悪い？

ここまでの実験の結果から，Numpy や Theano は悪くなくて，Pylearn2 がおかしなことになってるか，Pylearn2 も悪くなくて単純にマシンが遅いだけ，のいずれかと言えそうだとわかりました．ということで，Pylearn2 の tutorial でお勉強 - 3時間目 - まんぼう日記 の convolutional net のサンプルを上記2種類の条件で実行して，最初の1epochにかかる時間を見てみると…

  • 実験N1,T1と同様の条件： 23分16秒，スレッド数1，CPU使用率100%弱
  • 実験N2,T2と同様の条件： 23分15秒，スレッド数1，CPU使用率100%弱

 という結果になりました…Pylearn2が悪いのか？

 

むむー．どうしたもんかなあ．