Stimulator

機械学習とか好きな技術話とかエンジニア的な話とかを書く

XonshのException発生時のtracebackを見やすくする

スクリプト xonsh Python

- はじめに -

この記事は、Xonsh Advent Calendar 2017 - Qiita 15日目の記事です。

完全に遅刻しています。

3日間xonsh本家のコードを読みながら「あーでもないこーでもない」とやっており遅れました。

結論を先に述べてから、後半でその経緯も話します。

　

Xontribにしておいたので簡単に使えると思います。



アジェンダ

　

- PythonのStackTraceを見やすくする -

PythonのStackTraceを見やすくする方法を以下の記事に書きました。

vaaaaaanquish.hatenablog.com

この中でも、私が最も見やすいと感じたbacktraceを使って、xonshのTraceBack表示を短くします。

他のパッケージや、自作のシンタックスハイライト用parserでも上手くいくと思います。


　

- xonshのstderrにbacktraceを適応する -

結論から言うと以下のコードを~/.xonshrcに差し込むのが早いと思います。

import xonsh.tools
import backtrace
import sys

# backtraceパッケージの_flush()をOverride
# 元コード : https://github.com/nir0s/backtrace/blob/f2c8683ec53e4fa48ea8c99c196b201bf22fda3e/backtrace.py#L36
def __flush(message):
    st = message + '\n'
    sys.stderr.buffer.write(st.encode(encoding="utf-8"))
backtrace._flush=__flush

# xonshのprint_exception()をOverride
# 元コード : https://github.com/xonsh/xonsh/blob/230f77b2bc64cbc3e04837377252793f5d09b9ba/xonsh/tools.py#L798
def _print_exception(msg=None):    
    tpe, v, tb = sys.exc_info()
    backtrace.hook(tb=tb, tpe=tpe, value=v)
    if msg:
        msg = msg if msg.endswith('\n') else msg + '\n'
        sys.stderr.write(msg)
xonsh.tools.print_exception = _print_exception

※上記xonshrcは最小限のコードです


こんな感じになり、コンソール汚染が減ってハッピーです。
一部ユーザ名を加工しています。
f:id:vaaaaaanquish:20171218231935p:plain

特に後者のpandasのkey errorなどは、本来30行近いエラーが出力されるのですが、半分程度に収まっていますし、かなり作業がしやすいかと思います。

　
backtrace._flush()は元のソースコードが以下のようになっています。

def _flush(message):
    sys.stderr.write(message + '\n')
    sys.stderr.flush()

後述しますが、xonshはsys.stderr.bufferが使える環境であればsys.stderr.buffer.write、使えなければsys.stderr.writeを利用してエラー内容を出力するようになっています(ここの調査に1日半かかりました)。
よって、backtraceの_flushをOverrideする時は、適切にPython環境に合わせてどちらかを選択して書き換えてやるのが正解です。

上記のxonshrcより丁寧に、sys.version_infoでバージョンチェックをして書いてやると良いです。
私はPython2以下は小学生に馬鹿にされるので使わないため利用してません。

　
また、xonshではエラー発生時に「tracebackを取得して、ログに保存して、メッセージを表示する」といった内容をまとめたxonsh.tools.print_exceptionを必ず呼ぶようになっています。
上記xonshrcコードでは、そのxonsh.tools.print_exceptionの」ほぼ全てをそぎ取ってbacktraceに任せるという形を取っていますが、元のソースコードはそこそこ長くちゃんとしています。

元の機能をなるべく壊さないようOverrideする場合は、元ソースでtraceback.print_exc()となっている所をsys.exc_infoからのbacktrace.hockに書き換えてやるのが一番良いと思います。


　

- さらに見やすくするためにcoloramaのStyleを記述する -

backtraceパッケージでは、coloramaというANSIカラーコードを利用したカラーリングパッケージを使って、さらにStyleを変更する事が可能です。

上記xonshrcのbacktrace.hookする部分で、reverse(逆順表示)やstrip_path(ファイル名のみ表示)、styleのパラメータを設定してやれば良いです。
私は以下のようにしています。

import backtrace
from colorama import init, Fore, Style
STYLES = {
    'backtrace': Fore.YELLOW + '{0}',
    'error': Fore.RED + Style.BRIGHT + '{0}',
    'line': Fore.RED + Style.BRIGHT + '{0}',
    'module': '{0}',
    'context': Style.BRIGHT + Fore.GREEN + '{0}',
    'call': Fore.RED + '--> ' + Fore.YELLOW + Style.BRIGHT + '{0}',
}
backtrace.hook(reverse=True, strip_path=True, styles=STYLES, tb=tb, tpe=tpe, value=v)

これで以下のようにさらに情報量が減り、順番もトップを見るだけという感じになりました。
f:id:vaaaaaanquish:20171218230912p:plain

やったね。


　

- どのようにprint_exceptionが呼ばれているか -

ここからは蛇足です。
数日詰まっていた理由と解決に至った流れを書いておくものです。

　
以下のtools.print_exception()があらゆるException発生時に呼ばれる事はDocを見ても明確である。
xonsh/tools.py at 230f77b2bc64cbc3e04837377252793f5d09b9ba · xonsh/xonsh · GitHub
Tools (xonsh.tools) — xonsh 0.6.0.dev151 documentation

そして、xonshのshell上で入力される全てのコマンドやPythonスクリプトは、base_shell.default()にてコンパイルされ実行される。
https://github.com/xonsh/xonsh/blob/ff05ec33a22c1688674616a84ef66d65cef5b3c5/xonsh/base_shell.py#L313

default内3行目のpushメソッドが入力されたコードをcompileするものである。
ptk構成のshellの場合、以下_pushでOverrideされている。
https://github.com/xonsh/xonsh/blob/ff05ec33a22c1688674616a84ef66d65cef5b3c5/xonsh/ptk/shell.py#L123

正確にpushがOverrideされている箇所を示すと以下cmdloop。
https://github.com/xonsh/xonsh/blob/ff05ec33a22c1688674616a84ef66d65cef5b3c5/xonsh/ptk/shell.py#L145

　
pushは降ってきたスクリプトをPythonのexecer.compileに投げてコンパイルして返すものである。

push時に@(x=1/0)とすればSyntaxErrorをコンパイラが検知してExceptionを返す。
しかし、@(1/0)は算術なので実行時にExceptionが出る(ここでかなり躓いた)。

　
実行時のExceptionというのは、ここ(run_compiled_code)で走った結果起こったものである
https://github.com/xonsh/xonsh/blob/ff05ec33a22c1688674616a84ef66d65cef5b3c5/xonsh/base_shell.py#L330

xonsh.codecache.run_compiled_codeはただのexecするだけの関数である
https://github.com/xonsh/xonsh/blob/f544e63699a19d3990d2abf1ff082c9b5f48176d/xonsh/codecache.py#L58


pushもrun_compiled_codeもException発生時、tools.print_exceptionが呼ばれており、一見違いが分かりにくい。

ここで出てくるのが独自のstreem io用のClassであるTee。
このTeeは、Pythonのバージョンの違い(sys.hoge.bufferのあるなし)を考慮しつつ、stdoutとstderrを同じIOで処理しながら、エラー前に$XONSH_STDERR_PREFIX、後に$XONSH_STDERR_POSTFIXを付けて、ログに保存しながら出力するためのものである。
https://github.com/xonsh/xonsh/blob/ff05ec33a22c1688674616a84ef66d65cef5b3c5/xonsh/base_shell.py#L217

以下で_TeeStdインスタンス作った時sys.stderrやsys.stdoutを関連付けしてる。
https://github.com/xonsh/xonsh/blob/ff05ec33a22c1688674616a84ef66d65cef5b3c5/xonsh/base_shell.py#L238
https://github.com/xonsh/xonsh/blob/ff05ec33a22c1688674616a84ef66d65cef5b3c5/xonsh/base_shell.py#L132


この_TeeStdがsys.stderr.buffer.write(byte入力)を利用しているため、backtraceが利用するsys.stderr.write(string入力)とで噛み合わない上、Teeのインスタンス生成タイミングはコードをcompileした後なので「@(x=1/0)の時はcoloramaのcolorが適応されるけど、@(1/0)の時は適応されない何で…」という事象が発生し、xonshの動作を逐一追うことになった。

これが全貌。


　

- おわりに -

最終的にbacktrace._flushもsys.stderr.buffer.writeに合わせてやる事で解決したけど、絶対もっとスマートに出来ると思う。
というかTeeのインスタンス作るタイミングは、普通にissue立てても良さそう。


Xonshアドベントカレンダーも空きの日のネタを用意してたのに書けてないしなかなか…という感じ。

誰か書いて下さい…

qiita.com

　

vaaaaaanquish

関連記事