Python

pythonで現在実行されているコードの位置を出力してみる

More than 1 year has passed since last update.

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)