2.3. コードのデバッグ¶
著者: Gaël Varoquaux
この節では、コードベースをよく理解するためのツールを探索します: バグをみつけて修正するためのデバッグ
Python の科学技術コミュニティに限りませんが、その目的にあわせた方策で進めます。
事前準備
- Numpy
- IPython
- nosetests (http://readthedocs.org/docs/nose/en/latest/)
- pyflakes (http://pypi.python.org/pypi/pyflakes)
C のデバッグでは gdb
章の内容
2.3.1. バグを避ける¶
2.3.1.1. トラブルに遭遇しないためのコーディングベストプラクティス¶
私達全員がバグのあるコードを書きます。そのことを受け入れましょう。そして立ち向かいましょう。
コードをテストとデバッグを念頭に入れて書きましょう。
- Keep It Simple, Stupid (KISS).
動作しうるもので最も単純なものは何ですか?
- Don’t Repeat Yourself (DRY).
知識の中の各要素は、システム内で、単一で明確で確かな表現を持つべきです。
定数、アルゴリズム、など...
コードの相互依存を制限しましょう。(疎結合)
関数やモジュールに(数学的な名前でなく)意味のある名前をつけましょう
2.3.1.2. pyflakes: 高速な静的解析¶
Python での静的解析ツールはいくつかあります; その内いくつかを挙げると:
ここではこれは最も簡潔なツールとして pyflakes に焦点をしぼります。
高速で簡潔
構文エラー、インポートもれや名前のタイポを検出します。
他のツールでは flake8 がおすすめです、これは pyflakes や pep8 を組み合わせたようなツールです。つまり、pyflakes がやるような型エラーに加えて、flake8 は PEP8 の推奨スタイルガイドへの違反も検知します。
pyflakes (または flake8) をエディタや IDE に統合しておくことを強く薦めます。これにより 生産性が向上します 。
2.3.1.2.1. pyflakes を編集中ファイルで実行する¶
現在のバッファで pyflakes を実行させるようにキーバインドを設定できます。
kate では Menu: ‘settings -> configure kate
‘external tools’ でプラグイを有効にします
external Tools で pyflakes を追加します:
kdialog --title "pyflakes %filename" --msgbox "$(pyflakes %filename)"
TextMate では
メニューの: TextMate -> Preferences -> Advanced -> Shell variables で shell variable に追加します:
TM_PYCHECKER = /Library/Frameworks/Python.framework/Versions/Current/bin/pyflakes
こうすると Ctrl-Shift-V が pyflakes レポートにバインドされます。
vim では .vimrc に (F5 を pyflakes にバインドします):
autocmd FileType python let &mp = 'echo "*** running % ***" ; pyflakes %' autocmd FileType tex,mp,rst,python imap <Esc>[15~ <C-O>:make!^M autocmd FileType tex,mp,rst,python map <Esc>[15~ :make!^M autocmd FileType tex,mp,rst,python set autowrite
emacs では .emacs に (F5 を pyflakes にバインドします):
(defun pyflakes-thisfile () (interactive) (compile (format "pyflakes %s" (buffer-file-name))) ) (define-minor-mode pyflakes-mode "Toggle pyflakes mode. With no argument, this command toggles the mode. Non-null prefix argument turns on the mode. Null prefix argument turns off the mode." ;; The initial value. nil ;; The indicator for the mode line. " Pyflakes" ;; The minor mode bindings. '( ([f5] . pyflakes-thisfile) ) ) (add-hook 'python-mode-hook (lambda () (pyflakes-mode t)))
2.3.1.2.2. タイプ毎にスペルチェッカーが走るように統合する¶
vim では
pyflakes.vim プラグインを利用します:
http://www.vim.org/scripts/script.php?script_id=2441 から zip ファイルをダウンロードします
ファイルを
~/.vim/ftplugin/pythonに展開しますvimrc に
filetype plugin indent onがあることを確認してください
代替手段: syntastic を使う。同様の方法で
flake8や他のツール、あるいは他の言語でも、その場でのチェックを実行できるよう設定できます。
emacs では flymake モードを pyflake とともに利用します、ドキュメントが http://www.plope.com/Members/chrism/flymake-mode にあります: 以下を .emacs ファイルに追加します:
(when (load "flymake" t) (defun flymake-pyflakes-init () (let* ((temp-file (flymake-init-create-temp-buffer-copy 'flymake-create-temp-inplace)) (local-file (file-relative-name temp-file (file-name-directory buffer-file-name)))) (list "pyflakes" (list local-file)))) (add-to-list 'flymake-allowed-file-name-masks '("\\.py\\'" flymake-pyflakes-init))) (add-hook 'find-file-hook 'flymake-find-file-hook)
2.3.2. デバッグのワークフロー¶
軽微でないバグに遭遇した時こそ、デバッグ戦略を使うときです。銀の弾丸はありません。が、戦略が助けてくれます:
与えられた問題をデバッグするには、少ないコード行数内に切り分けて、フレームワークやアプリケーションコードから離れて、、修正・変更・実行のサイクルを回すことが好ましい状況です
確実に失敗する状況にしましょう。コードが毎回失敗するようなテストケースを見つけましょう。
分割して統治せよ。テストケースが失敗する状況になったら失敗するコードを切り分けましょう。
どのモジュールで。
どの関数で。
コードのどの行で。
再現可能な失敗を小さく切り出しましょう: テストケース
一つ変更したら、失敗するテストケースを再実行しましょう。
何が間違っているのか理解するためにデバッガを使いましょう。
ノートをとって、辛抱強く。時間がかかることもあります。
注釈
このプロセスを経て: バグを再現するコード片がしっかりと切り出し、このコード片を使ってバグを修正し、対応するコードをテストケースに追加します。
2.3.3. Python デバッガを利用する¶
python のデバッガ pdb: https://docs.python.org/library/pdb.html を使うことでコードを対話的に検査することができます。
とりわけ、以下ができます:
ソースコードを閲覧する。
コールスタックの上下移動。
変数の値の検査。
変数の値の変更。
ブレークポイントの設定。
そう print 文もデバッグツールとして動作します。しかし、実行時に検査する場合はデバッガを利用する方が効率的です。
2.3.3.1. デバッガの呼び出し¶
デバッガを起動する方法
検死、モジュールエラー後にデバッガを起動
デバッガとともにモジュールを起動する
モジュール内でデバッガを呼び出す
2.3.3.1.1. 検死¶
状況: IPython を動かしていて、traceback に遭遇したとき。
ここで index_error.py ファイルをデバッグしてみましょう。動かすと IndexError が送出されます。 %debug をタイプしてデバッガに入ります。
In [1]: %run index_error.py
---------------------------------------------------------------------------
IndexError Traceback (most recent call last)
/home/varoquau/dev/scipy-lecture-notes/advanced/debugging/index_error.py in <module>()
6
7 if __name__ == '__main__':
----> 8 index_error()
9
/home/varoquau/dev/scipy-lecture-notes/advanced/debugging/index_error.py in index_error()
3 def index_error():
4 lst = list('foobar')
----> 5 print lst[len(lst)]
6
7 if __name__ == '__main__':
IndexError: list index out of range
In [2]: %debug
> /home/varoquau/dev/scipy-lecture-notes/advanced/debugging/index_error.py(5)index_error()
4 lst = list('foobar')
----> 5 print lst[len(lst)]
6
ipdb> list
1 """Small snippet to raise an IndexError."""
2
3 def index_error():
4 lst = list('foobar')
----> 5 print lst[len(lst)]
6
7 if __name__ == '__main__':
8 index_error()
9
ipdb> len(lst)
6
ipdb> print lst[len(lst)-1]
r
ipdb> quit
In [3]:
IPython なしで検死デバッグ
IPython を利用できない場合にもあるでしょう、例えばコマンドラインから呼び出してスクリプトをデバッグするときなど。このような場合には python -m pdb script.py を呼び出すことができます:
$ python -m pdb index_error.py
> /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/index_error.py(1)<module>()
-> """Small snippet to raise an IndexError."""
(Pdb) continue
Traceback (most recent call last):
File "/usr/lib/python2.6/pdb.py", line 1296, in main
pdb._runscript(mainpyfile)
File "/usr/lib/python2.6/pdb.py", line 1215, in _runscript
self.run(statement)
File "/usr/lib/python2.6/bdb.py", line 372, in run
exec cmd in globals, locals
File "<string>", line 1, in <module>
File "index_error.py", line 8, in <module>
index_error()
File "index_error.py", line 5, in index_error
print lst[len(lst)]
IndexError: list index out of range
Uncaught exception. Entering post mortem debugging
Running 'cont' or 'step' will restart the program
> /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/index_error.py(5)index_error()
-> print lst[len(lst)]
(Pdb)
2.3.3.1.2. ステップ毎の実行¶
状況: バグがモジュール内にあるが、どこにあるかまでわからない場合。
例として wiener_filtering.py をデバッグしましょう。コードは実行できますが、フィルタがうまく動作しません。
%run -d wiener_filtering.pを利用して IPython をデバッガつきで走らせます:In [1]: %run -d wiener_filtering.py *** Blank or comment *** Blank or comment *** Blank or comment Breakpoint 1 at /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/wiener_filtering.py:4 NOTE: Enter 'c' at the ipdb> prompt to start your script. > <string>(1)<module>()
b 34で34行目にブレークポイントを設定します:ipdb> n > /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/wiener_filtering.py(4)<module>() 3 1---> 4 import numpy as np 5 import scipy as sp ipdb> b 34 Breakpoint 2 at /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/wiener_filtering.py:34
c(ont(inue))を利用して次のブレークポイントまで実行を続けます。ipdb> c > /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/wiener_filtering.py(34)iterated_wiener() 33 """ 2--> 34 noisy_img = noisy_img 35 denoised_img = local_mean(noisy_img, size=size)
n(ext)とs(tep)を利用してコードステップを進めます:next現在の実行コンテキストで次の文に進めますがstepは実行コンテキストをまたぎます、つまり関数呼び出しの内部まで探索します:ipdb> s > /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/wiener_filtering.py(35)iterated_wiener() 2 34 noisy_img = noisy_img ---> 35 denoised_img = local_mean(noisy_img, size=size) 36 l_var = local_var(noisy_img, size=size) ipdb> n > /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/wiener_filtering.py(36)iterated_wiener() 35 denoised_img = local_mean(noisy_img, size=size) ---> 36 l_var = local_var(noisy_img, size=size) 37 for i in range(3):
数行ステップを進めてローカル変数を探索します:
ipdb> n > /home/varoquau/dev/scipy-lecture-notes/advanced/optimizing/wiener_filtering.py(37)iterated_wiener() 36 l_var = local_var(noisy_img, size=size) ---> 37 for i in range(3): 38 res = noisy_img - denoised_img ipdb> print l_var [[5868 5379 5316 ..., 5071 4799 5149] [5013 363 437 ..., 346 262 4355] [5379 410 344 ..., 392 604 3377] ..., [ 435 362 308 ..., 275 198 1632] [ 548 392 290 ..., 248 263 1653] [ 466 789 736 ..., 1835 1725 1940]] ipdb> print l_var.min() 0
なんということでしょう、整数のみで 0 を含んでいました。これがバグでした、整数演算していました。
数値エラーの際に例外を送出する
wiener_filtering.py ファイルを実行すると以下の警告が送出されます:
In [2]: %run wiener_filtering.py
wiener_filtering.py:40: RuntimeWarning: divide by zero encountered in divide
noise_level = (1 - noise/l_var )
この警告を例外にすることができ、それにより検死デバッグして、問題をすばやく見つけられます:
In [3]: np.seterr(all='raise')
Out[3]: {'divide': 'print', 'invalid': 'print', 'over': 'print', 'under': 'ignore'}
In [4]: %run wiener_filtering.py
---------------------------------------------------------------------------
FloatingPointError Traceback (most recent call last)
/home/esc/anaconda/lib/python2.7/site-packages/IPython/utils/py3compat.pyc in execfile(fname, *where)
176 else:
177 filename = fname
--> 178 __builtin__.execfile(filename, *where)
/home/esc/physique-cuso-python-2013/scipy-lecture-notes/advanced/debugging/wiener_filtering.py in <module>()
55 pl.matshow(noisy_face[cut], cmap=pl.cm.gray)
56
---> 57 denoised_face = iterated_wiener(noisy_face)
58 pl.matshow(denoised_face[cut], cmap=pl.cm.gray)
59
/home/esc/physique-cuso-python-2013/scipy-lecture-notes/advanced/debugging/wiener_filtering.py in iterated_wiener(noisy_img, size)
38 res = noisy_img - denoised_img
39 noise = (res**2).sum()/res.size
---> 40 noise_level = (1 - noise/l_var )
41 noise_level[noise_level<0] = 0
42 denoised_img += noise_level*res
FloatingPointError: divide by zero encountered in divide
2.3.3.1.3. デバッガを起動する他の方法¶
例外送出を手軽なブレークポイントとして使う
ブレークポイントを設定するために、行数を書き留めておくのが手間に感じられる場合は、検査したい場所で単に例外を送出して、IPython の
%debugを使うことができます。ただし、そうする場合はステップ実行や継続はできません。nosetests を利用してテストの失敗をデバッグ
nosetests --pdbを実行して例外時の検死デバッグできます、そしてnosetests --pdb-failureでテストの失敗をデバッガーを利用して検査できます。さらに ipdbplugin をインストールすることで node 内デバッガに IPython インターフェースを使うことができます。nosetests に
--ipdbや--ipdb-failureオプションを渡します。デバッガを明示的に呼び出す
次の行をデバッガに入りたい場所に挿れます:
import pdb; pdb.set_trace()
警告
nosetests を実行すると出力がキャプチャされるので、デバッガが動いてないように見えます。 -s フラグをつけて単純に nosetests を動かします。
2.3.3.2. デバッガーコマンドと対話操作¶
l(list) |
現在の場所のコードを表示する |
u(p) |
コールスタックを上に移動する |
d(own) |
コールスタックを下に移動する |
n(ext) |
次の行を実行(新しい関数の中に降りません) |
s(tep) |
次の文を実行します(新しい関数内に降ります) |
bt |
コールスタックを表示します |
a |
ローカル変数を表示します |
!command |
与えた Python コマンドを実行します(pdb コマンドではなく |
警告
デバッガコマンドは Python コードではありません
変数に使いたい名前をつけることができません。例えば、現在のフレーム内と同じ名前で変数を上書きできません: デバッガでコードをタイプするときにはローカル変数と異なる名前を使いましょう.
2.3.3.2.1. デバッガ内のヘルプ表示¶
h や help とタイプすることで、対話的なヘルプにアクセスできます:
ipdb> help
Documented commands (type help <topic>):
========================================
EOF bt cont enable jump pdef r tbreak w
a c continue exit l pdoc restart u whatis
alias cl d h list pinfo return unalias where
args clear debug help n pp run unt
b commands disable ignore next q s until
break condition down j p quit step up
Miscellaneous help topics:
==========================
exec pdb
Undocumented commands:
======================
retval rv
2.3.4. gdb を利用してセグメンテーションフォルトをデバッグ¶
セグメンテーションフォルトに遭遇した場合は pdb でデバッグすることはできません、デバッガに入る前の Python インタプリタがクラッシュするので。同様に Python に埋め込まれた C コードにバグがある場合も pdb は使えません。この場合は GNU デバッガ gdb が Linux で利用できます。
gdb を使う前に Python に特化したツールについて触れておきましょう。そのために ~/.gdbinit にいくつかのマクロを追加します。最適なマクロの選択は Python や gdb のバージョンによって替わります。単純化したものを gdbinit に追加しておきましたが DebuggingWithGdb を読んでみてもいいでしょう。
gdb で Python スクリプト segfault.py をデバッグするために以下のようにして gdb 内でスクリプトを実行できます。
$ gdb python
...
(gdb) run segfault.py
Starting program: /usr/bin/python segfault.py
[Thread debugging using libthread_db enabled]
Program received signal SIGSEGV, Segmentation fault.
_strided_byte_copy (dst=0x8537478 "\360\343G", outstrides=4, src=
0x86c0690 <Address 0x86c0690 out of bounds>, instrides=32, N=3,
elsize=4)
at numpy/core/src/multiarray/ctors.c:365
365 _FAST_MOVE(Int32);
(gdb)
セグメンテーションフォルトに遭遇して、gdb が キャプチャして (Python のコールスタックではなく) Cレベルスタックで検死デバッグします。gdb コマンドを利用して C コールスタックをデバッグできます。
(gdb) up
#1 0x004af4f5 in _copy_from_same_shape (dest=<value optimized out>,
src=<value optimized out>, myfunc=0x496780 <_strided_byte_copy>,
swap=0)
at numpy/core/src/multiarray/ctors.c:748
748 myfunc(dit->dataptr, dest->strides[maxaxis],
見てわかるように numpy の Cコード内にいます。このセグメンテーションフォルトがどの Python コードで引き起こされたのか知りたいので、Python の実行ループまでスタックを上に移動します:
(gdb) up
#8 0x080ddd23 in call_function (f=
Frame 0x85371ec, for file /home/varoquau/usr/lib/python2.6/site-packages/numpy/core/arrayprint.py, line 156, in _leading_trailing (a=<numpy.ndarray at remote 0x85371b0>, _nc=<module at remote 0xb7f93a64>), throwflag=0)
at ../Python/ceval.c:3750
3750 ../Python/ceval.c: No such file or directory.
in ../Python/ceval.c
(gdb) up
#9 PyEval_EvalFrameEx (f=
Frame 0x85371ec, for file /home/varoquau/usr/lib/python2.6/site-packages/numpy/core/arrayprint.py, line 156, in _leading_trailing (a=<numpy.ndarray at remote 0x85371b0>, _nc=<module at remote 0xb7f93a64>), throwflag=0)
at ../Python/ceval.c:2412
2412 in ../Python/ceval.c
(gdb)
Python の実行ループに入ってしまえば、特別な Python ヘルパー関数を利用することができます。例えば Python コードの該当する行を見つけるなど:
(gdb) pyframe
/home/varoquau/usr/lib/python2.6/site-packages/numpy/core/arrayprint.py (158): _leading_trailing
(gdb)
これは numpy コードなのでで、自分で書いたコードに辿りつくまで上に移動する必要があります:
(gdb) up
...
(gdb) up
#34 0x080dc97a in PyEval_EvalFrameEx (f=
Frame 0x82f064c, for file segfault.py, line 11, in print_big_array (small_array=<numpy.ndarray at remote 0x853ecf0>, big_array=<numpy.ndarray at remote 0x853ed20>), throwflag=0) at ../Python/ceval.c:1630
1630 ../Python/ceval.c: No such file or directory.
in ../Python/ceval.c
(gdb) pyframe
segfault.py (12): print_big_array
該当するコードは:
def make_big_array(small_array):
big_array = stride_tricks.as_strided(small_array,
shape=(2e6, 2e6), strides=(32, 32))
return big_array
def print_big_array(small_array):
big_array = make_big_array(small_array)
このようにセグメンテーションフォルトが big_array[-10:] を表示する際に起きていました。この理由は単にプログラムのメモリの外まで big_array の終端が確保しているからでした。
注釈
gdbinit で定義された特別な Python コマンド一覧のために、このファイルのソースをみておきましょう。
まとめの演習
以下のスクリプトはドキュメントが十分に書かれているので判読できそうです。数値計算で興味ある問題の答えを探しているようですが、うまく動作していません...これをデバッグできますか?
Python ソースコード: to_debug.py
"""
A script to compare different root-finding algorithms.
This version of the script is buggy and does not execute. It is your task
to find an fix these bugs.
The output of the script sould look like:
Benching 1D root-finder optimizers from scipy.optimize:
brenth: 604678 total function calls
brentq: 594454 total function calls
ridder: 778394 total function calls
bisect: 2148380 total function calls
"""
from itertools import product
import numpy as np
from scipy import optimize
FUNCTIONS = (np.tan, # Dilating map
np.tanh, # Contracting map
lambda x: x**3 + 1e-4*x, # Almost null gradient at the root
lambda x: x+np.sin(2*x), # Non monotonous function
lambda x: 1.1*x+np.sin(4*x), # Fonction with several local maxima
)
OPTIMIZERS = (optimize.brenth, optimize.brentq, optimize.ridder,
optimize.bisect)
def apply_optimizer(optimizer, func, a, b):
""" Return the number of function calls given an root-finding optimizer,
a function and upper and lower bounds.
"""
return optimizer(func, a, b, full_output=True)[1].function_calls,
def bench_optimizer(optimizer, param_grid):
""" Find roots for all the functions, and upper and lower bounds
given and return the total number of function calls.
"""
return sum(apply_optimizer(optimizer, func, a, b)
for func, a, b in param_grid)
def compare_optimizers(optimizers):
""" Compare all the optimizers given on a grid of a few different
functions all admitting a signle root in zero and a upper and
lower bounds.
"""
random_a = -1.3 + np.random.random(size=100)
random_b = .3 + np.random.random(size=100)
param_grid = product(FUNCTIONS, random_a, random_b)
print "Benching 1D root-finder optimizers from scipy.optimize:"
for optimizer in OPTIMIZERS:
print '% 20s: % 8i total function calls' % (
optimizer.__name__,
bench_optimizer(optimizer, param_grid)
)
if __name__ == '__main__':
compare_optimizers(OPTIMIZERS)