例外が起きた時、エラーメッセージやスタックトレースは便利ですが、例外を起こした値自体も気になります。
そんなときに、例外が起きた関数で使われていたローカル変数がわかると役に立ちます。
ローカル変数の値がわかれば、例外を起こした値自体がわからなくても、それを導くための変数がわかります。
tl;dr
- Pythonでは例外のtracebackを見ると例外発生時のローカル変数がわかる
- OpenTelemetryでローカル変数を記録するためには、
record_exceptionをラップすればOK - パッケージを作りました
パッケージを作りました
まずは結果から。
下のようにOpenTelemetryのexceptionのイベントの中に例外発生時のローカル変数を追加することができます。
{
...,
"events": [
{
"name": "exception",
"attributes": {
"exception.type": "Exception",
"exception.message": "exception: hello, 1234, True",
"exception.stacktrace": "Traceback (most recent call last) ...",
"exception.escaped": "False",
"local.var.text_arg": "hello", // <= "text_arg"という変数とその値が追加された
"local.var.int_arg": 1234, // <= "int_arg"という変数とその値が追加された
"local.var.bool_var": true, // <= "bool_var"という変数とその値が追加された
"local.function.filename": "/path/to/main.py", // <= 例外が起きたファイル名
"local.function.name": "raise_exception", // <= 例外が起きた関数名
"local.function.lineno": 16 // <= 例外が起きた行数
}
}
]
}
これはpython-opentelemetry-exception-extを使って例外を記録した時の結果です。
汎用的に使えるようにしているので、Djangoなどでも動きます。
下のように enable_local_variables_recording を最初に1回呼ぶだけで、ローカル変数を記録するようになります。
from opentelemetry.exception.ext import enable_local_variables_recording
enable_local_variables_recording()
ここから先では enable_local_variables_recording() の仕組みについて解説します。
例外時のローカル変数を取得する方法
Pythonの例外にはファイル名や行数の情報と一緒に、raiseから戻ってきた各関数フレームの情報も入っています。
具体的には、BaseException以下にある__traceback__ というプロパティにデータが格納されています。
tracebackオブジェクトにあるtb_frameの中に、関数名と一緒に、その関数で使用していた変数の情報が入っています。
また、tracebackは1つ分のフレームの情報を保持していて、tb_nextをたどることで子のtracebackを取得することができるようになっています。
コードにすると、わかりやすいかなと思うのですが、
def a():
a_var = 'a'
try:
b()
except Exception as e:
return e
def b():
b_var = 'b'
c()
def c():
c_var = 'c'
raise Exception
exc = a()
traceback = exc.__traceback__
while traceback:
frame = traceback.tb_frame
print(f"{frame.f_code.co_filename}:{frame.f_lineno}")
for name, value in frame.f_locals.items():
print(f" {name}={value}")
traceback = traceback.tb_next
これを実行すると、下のように出力されます。
/path/to/file.py:6
a_var=a
/path/to/file.py:10
b_var=b
/path/to/file.py:14
c_var=c
tb_frameから、関数名と一緒に各フレームの変数が取得できていることがわかります。
こうして、目的の関数の中で使われていた変数を取得できるわけです。
ちなみに、__traceback__という、アクセスしてほしくなさそうなプロパティを使っていいのかという議論があると思うのですが、Djangoが使っていたので「じゃぁいいかな」と思って使っています。
OpenTelemetryに記録する方法
変数が取れたので、それをOpenTelemetryに乗せます。
PythonのOpenTelemetryでは、例外を発見すると Span.record_exceptionという関数を呼び出して例外の情報を記録します。
そこで、この関数をラップして、関数内の変数の情報をattributesに追加します。
具体的には、次のようにラップします。
def decorate_method(self, method: Callable) -> Callable:
def decorate(*original_args, **original_kwargs):
args = list(original_args)
kwargs = original_kwargs.copy()
try:
exception = args[0]
if exception is not None:
attributes = kwargs["attributes"]
local_vars = extract_local_variables(exception) # <- ここで前節のやり方で変数を取得
attributes.update(local_vars) # <- ここで変数をattributesに追加
except Exception:
args = original_args
kwargs = original_kwargs
return method(*args, **kwargs)
return decorate
Span.record_exception = decorate_method(Span.record_exception)
こうすると、OpenTelemetryのexception用イベントに変数を追加できるようになります。
終わりに
柔軟性をもたせるためには、更にどの関数を取得するか考えたりする必要がありますが、基本的にはこれで取得できます。
python-opentelemetry-exception-extは今まで書いたものをまとめてenable_local_variables_recordingという関数から呼び出せるようにしているわけです。
以上、例外時のローカル変数をOpenTelemetryに記録する方法でした。
パッケージ自体もよろしくお願いします。
Discussion