pythonで現在実行されているコードの位置を出力してみたい。これは実行中のスタックトレースを表示できれば良いという話。
特定の位置でのスタックトレースの表示はそれなりに簡単なのだけれど。任意の位置で現在実行中のコードの位置を表示したい。
特定の位置でのスタックトレース
特定の位置でその時のスタックトレースを出すのは簡単でtracebackモジュールを使えば良い。以下の様な感じ。
import traceback
def f():
g()
def g():
h()
def h():
traceback.print_stack()
以下のような出力が手に入る。
File "qr_277wGF.py", line 16, in <module>
f()
File "qr_277wGF.py", line 5, in f
g()
File "qr_277wGF.py", line 9, in g
h()
File "qr_277wGF.py", line 13, in h
traceback.print_stack()
スタックトレースを表示する関数をwrapする
自分の好みな形に調整したい場合には関数で包む。そのままprint_stack()
を使ってしまうと1段階余計に表示されてしまう。
def mytrace():
print("----------------------------------------")
traceback.print_stack()
def f():
g()
def g():
mytrace()
f()
ここでgが底になってほしいのだけれど自分で定義したmytrace()
が表示されてしまう。
----------------------------------------
File "qr_277XlX.py", line 18, in <module>
f()
File "qr_277XlX.py", line 11, in f
g()
File "qr_277XlX.py", line 15, in g
mytrace()
File "qr_277XlX.py", line 7, in mytrace
traceback.print_stack()
その場合にはframeオブジェクトをそのまま渡してあげれば良い。sys._getframe()
に現在位置から切り捨てたい深さを指定する(あるいはf.f_backで1つ上の階層に行く)。
import sys
import traceback
def mytrace():
print("----------------------------------------")
f = sys._getframe(1)
traceback.print_stack(f)
def f():
g()
def g():
mytrace()
f()
良い感じ。
----------------------------------------
File "qr_277x5j.py", line 19, in <module>
f()
File "qr_277x5j.py", line 12, in f
g()
File "qr_277x5j.py", line 16, in g
mytrace()
現在の実行位置のスタックトレースを表示する
現在の実行位置のスタックトレースを表示するのはsignal経由で行うと良い。
何故かと言うと、メインスレッドで実行されるので。
Python のシグナルハンドラは、もしシグナルを受け取ったのが別のスレッドだったとしても、常に Python のメインスレッドで実行されます。このためシグナルをスレッド間通信に使うことはできません。代わりに threading モジュールが提供している同期プリミティブを利用できます。
というわけで、たとえばCtrl-c
でその時の実行位置を出力するには、SIGINTを監視するシグナルハンドラを指定してあげれば良い。
import os
import sys
import threading
import time
import signal
import traceback
def main():
def print_stack(signum, tb):
f = sys._getframe(1)
print("----------------------------------------")
traceback.print_stack(f, limit=None, file=sys.stdout)
signal.signal(signal.SIGINT, print_stack)
f(1)
f(2)
f(3)
def f(n):
for i in range(n):
g(i)
time.sleep(0.5)
def g(n):
for i in range(n):
h(i)
time.sleep(0.5)
def h(n):
for i in range(n):
h(i)
time.sleep(0.5)
if __name__ == "__main__":
main()
Ctrl-c
を押すたびにその時の位置を出力するようになる。
$ python 01sig.py
^C----------------------------------------
File "01sig.py", line 41, in <module>
main()
File "01sig.py", line 18, in main
f(2)
File "01sig.py", line 25, in f
time.sleep(0.5)
^C----------------------------------------
File "01sig.py", line 41, in <module>
main()
File "01sig.py", line 18, in main
f(2)
File "01sig.py", line 24, in f
g(i)
File "01sig.py", line 31, in g
time.sleep(0.5)
^C----------------------------------------
File "01sig.py", line 41, in <module>
main()
File "01sig.py", line 19, in main
f(3)
File "01sig.py", line 25, in f
time.sleep(0.5)
^C----------------------------------------
File "01sig.py", line 41, in <module>
main()
File "01sig.py", line 19, in main
f(3)
File "01sig.py", line 25, in f
time.sleep(0.5)
^C----------------------------------------
File "01sig.py", line 41, in <module>
main()
File "01sig.py", line 19, in main
f(3)
File "01sig.py", line 24, in f
g(i)
File "01sig.py", line 31, in g
time.sleep(0.5)
定期的に現在の実行位置を表示する
人間がCtrl-c
を入力するのも面倒だったりすることがある。そういう時には定期的に出力するようにしたい。こういうときはbackgroundでthreadを動かしておくと良いかもしれない。threading.Timerを再帰的に実行する。
import os
import sys
import threading
import time
import signal
import traceback
def main():
p = os.getpid()
def ping():
os.kill(p, signal.SIGUSR1)
def print_stack(signum, tb):
f = sys._getframe(1)
print("----------------------------------------")
traceback.print_stack(f, limit=None, file=sys.stdout)
signal.signal(signal.SIGUSR1, print_stack)
stop = False
interval = 0.5
def tick():
nonlocal stop
ping()
if not stop:
th = threading.Timer(interval, tick)
th.setDaemon(True)
th.start()
return th
tick()
f(1)
f(2)
f(3)
def f(n):
for i in range(n):
g(i)
time.sleep(0.5)
def g(n):
for i in range(n):
h(i)
time.sleep(0.5)
def h(n):
for i in range(n):
h(i)
time.sleep(0.5)
if __name__ == "__main__":
main()
良い感じ。
$ python 00sig.py
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 34, in main
tick()
File "00sig.py", line 27, in tick
ping()
File "00sig.py", line 13, in ping
os.kill(p, signal.SIGUSR1)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 36, in main
f(2)
File "00sig.py", line 43, in f
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 36, in main
f(2)
File "00sig.py", line 42, in f
g(i)
File "00sig.py", line 49, in g
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 36, in main
f(2)
File "00sig.py", line 43, in f
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 37, in main
f(3)
File "00sig.py", line 43, in f
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 37, in main
f(3)
File "00sig.py", line 42, in f
g(i)
File "00sig.py", line 49, in g
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 37, in main
f(3)
File "00sig.py", line 43, in f
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 37, in main
f(3)
File "00sig.py", line 42, in f
g(i)
File "00sig.py", line 49, in g
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 37, in main
f(3)
File "00sig.py", line 42, in f
g(i)
File "00sig.py", line 48, in g
h(i)
File "00sig.py", line 55, in h
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 37, in main
f(3)
File "00sig.py", line 42, in f
g(i)
File "00sig.py", line 49, in g
time.sleep(0.5)
----------------------------------------
File "00sig.py", line 59, in <module>
main()
File "00sig.py", line 37, in main
f(3)
File "00sig.py", line 43, in f
time.sleep(0.5)