sys.settraceとthreading.settrace

先日、sys.settrace()　について書きましたが、今日はその続きとなります。
今日は、スレッド環境でスクリプトをトレースする方法を試してみました。

こんな感じのスクリプトを書いてみました。
このスクリプトは、説明するまでもなく、２つのスレッド（Thread_A, Thread_B）
から関数 main() を呼び出しています。

関数main()では、0, 1という値をprint分で出力します。
(出力結果が長くなるので、ループ回数を減らしました)

# -*- coding: utf-8 -*-

import sys
import threading
import time


#
#
def func_a(val):
    print 'value = %d' % val
    time.sleep(0.1)

#
#
def main():
    print 'Begin'

    for i in range(2):
        func_a(i)

    print 'End'

#
#
class Thread_A(threading.Thread):
    def __init__(self):
        print 'ThreadA'
        threading.Thread.__init__(self)

    def run(self):
        print 'Start A'
        main()
	
#
#
class Thread_B(threading.Thread):
    def __init__(self):
        print 'ThreadB'
        threading.Thread.__init__(self)

    def run(self):
        print 'Start B'
        main()

#
#
if __name__ == '__main__':
    ##
    def func_trace(frame, event, arg):
        '''
        トレース用の関数。引数の詳細はリファレンスで確認してください。
        frame : スタックフレームの情報
        event : 発生したイベントの種類(文字列)
        arg   : 常にNoneのようです。
        '''
        print '[%s] -> %s: (%s) <%s>' % (event,
				    frame.f_globals.get('__file__'),
				    frame.f_lineno,
                    threading.currentThread().getName())

        return func_trace

    # threadingにトレース用の関数を設定。
    # この部分をsys.settrace(func_trace)に置き換えると、
    # 出力結果(スレッド名)が<MainThread>となるようです。
    threading.settrace(func_trace)
    
    A = Thread_A()
    A.start()
	
    B = Thread_B()
    B.start()

    A.join()
    B.join()

    print 'terminated'

実行結果は以下のようになりました。

[kani@arch-slime src]$ python trace_test.py
ThreadA
[call] -> trace_test.py: (31)
[line] -> trace_test.py: (32)
Start A
[line] -> trace_test.py: (33)
[call] -> trace_test.py: (16)
[line] -> trace_test.py: (17)
Begin
[line] -> trace_test.py: (19)
[line] -> trace_test.py: (20)
[call] -> trace_test.py: (10)
[line] -> trace_test.py: (11)
value = 0
[line] -> trace_test.py: (12)
ThreadB
[call] -> trace_test.py: (42)
[line] -> trace_test.py: (43)
Start B
[line] -> trace_test.py: (44)
[call] -> trace_test.py: (16)
[line] -> trace_test.py: (17)
Begin
[line] -> trace_test.py: (19)
[line] -> trace_test.py: (20)
[call] -> trace_test.py: (10)
[line] -> trace_test.py: (11)
value = 0
[line] -> trace_test.py: (12)
[return] -> trace_test.py: (12)
[line] -> trace_test.py: (19)
[line] -> trace_test.py: (20)
[call] -> trace_test.py: (10)
[line] -> trace_test.py: (11)
value = 1
[line] -> trace_test.py: (12)
[return] -> trace_test.py: (12)
[line] -> trace_test.py: (19)
[line] -> trace_test.py: (20)
[call] -> trace_test.py: (10)
[line] -> trace_test.py: (11)
value = 1
[line] -> trace_test.py: (12)
[return] -> trace_test.py: (12)
[line] -> trace_test.py: (19)
[line] -> trace_test.py: (22)
End
[return] -> trace_test.py: (22)
[return] -> trace_test.py: (33)
[call] -> /usr/lib/python2.5/threading.pyc: (44)
[line] -> /usr/lib/python2.5/threading.pyc: (45)
[return] -> /usr/lib/python2.5/threading.pyc: (45)
[call] -> /usr/lib/python2.5/threading.pyc: (539)
[line] -> /usr/lib/python2.5/threading.pyc: (540)
[line] -> /usr/lib/python2.5/threading.pyc: (541)
[line] -> /usr/lib/python2.5/threading.pyc: (542)
[call] -> /usr/lib/python2.5/threading.pyc: (267)
[line] -> /usr/lib/python2.5/threading.pyc: (268)
[call] -> /usr/lib/python2.5/threading.pyc: (249)
[line] -> /usr/lib/python2.5/threading.pyc: (250)
[call] -> /usr/lib/python2.5/threading.pyc: (198)
[line] -> /usr/lib/python2.5/threading.pyc: (201)
[line] -> /usr/lib/python2.5/threading.pyc: (205)
[return] -> /usr/lib/python2.5/threading.pyc: (205)
[line] -> /usr/lib/python2.5/threading.pyc: (252)
[line] -> /usr/lib/python2.5/threading.pyc: (253)
[line] -> /usr/lib/python2.5/threading.pyc: (254)
[line] -> /usr/lib/python2.5/threading.pyc: (258)
[line] -> /usr/lib/python2.5/threading.pyc: (259)
[call] -> /usr/lib/python2.5/threading.pyc: (44)
[line] -> /usr/lib/python2.5/threading.pyc: (45)
[return] -> /usr/lib/python2.5/threading.pyc: (45)
[line] -> /usr/lib/python2.5/threading.pyc: (260)
[line] -> /usr/lib/python2.5/threading.pyc: (261)
[line] -> /usr/lib/python2.5/threading.pyc: (262)
[line] -> /usr/lib/python2.5/threading.pyc: (263)
[line] -> /usr/lib/python2.5/threading.pyc: (260)
[return] -> /usr/lib/python2.5/threading.pyc: (260)
[return] -> /usr/lib/python2.5/threading.pyc: (268)
[line] -> /usr/lib/python2.5/threading.pyc: (543)
[return] -> /usr/lib/python2.5/threading.pyc: (543)

[return] -> trace_test.py: (12)
[line] -> trace_test.py: (19)
[line] -> trace_test.py: (22)
End
[return] -> trace_test.py: (22)
[return] -> trace_test.py: (44)
[call] -> /usr/lib/python2.5/threading.pyc: (44)
[line] -> /usr/lib/python2.5/threading.pyc: (45)
[return] -> /usr/lib/python2.5/threading.pyc: (45)
[call] -> /usr/lib/python2.5/threading.pyc: (539)
[line] -> /usr/lib/python2.5/threading.pyc: (540)
[line] -> /usr/lib/python2.5/threading.pyc: (541)
[line] -> /usr/lib/python2.5/threading.pyc: (542)
[call] -> /usr/lib/python2.5/threading.pyc: (267)
[line] -> /usr/lib/python2.5/threading.pyc: (268)
[call] -> /usr/lib/python2.5/threading.pyc: (249)
[line] -> /usr/lib/python2.5/threading.pyc: (250)
[call] -> /usr/lib/python2.5/threading.pyc: (198)
[line] -> /usr/lib/python2.5/threading.pyc: (201)
[line] -> /usr/lib/python2.5/threading.pyc: (205)
[return] -> /usr/lib/python2.5/threading.pyc: (205)
[line] -> /usr/lib/python2.5/threading.pyc: (252)
[line] -> /usr/lib/python2.5/threading.pyc: (253)
[line] -> /usr/lib/python2.5/threading.pyc: (254)
[line] -> /usr/lib/python2.5/threading.pyc: (256)
[call] -> /usr/lib/python2.5/threading.pyc: (44)
[line] -> /usr/lib/python2.5/threading.pyc: (45)
[return] -> /usr/lib/python2.5/threading.pyc: (45)
[line] -> /usr/lib/python2.5/threading.pyc: (257)
[return] -> /usr/lib/python2.5/threading.pyc: (257)
[return] -> /usr/lib/python2.5/threading.pyc: (268)
[line] -> /usr/lib/python2.5/threading.pyc: (543)
[return] -> /usr/lib/python2.5/threading.pyc: (543)
terminated

上記の結果の後半に「/usr/lib/python2.5/threading.pyc」という出力が
ありますが、スレッドの後始末の処理の部分だと思うので
あまり気にしなくていいかな。。と思っています。

一応、複数のスレッドの場合でもトレースできています。
今回の実験では、トレース用の関数がどのスレッドから呼ばれたかを
知るために、threading.currentThread()を使ってみました。

今回試した方法がそのままデバッガに使えることはないかもしれませんが、
なかなか勉強になりました。