LangfuseではトレースのLatencyにトレースの処理時間は考慮されないらしい

## はじめに

先日、[Langfuse Night #1](https://connpass.com/event/340099/)というイベントでLTをさせていただきました。LTの資料をベースに、その際にできなかった補足説明を書いていきたいと思います。

ちなみに、資料は下記のリンク先から参照できます。

https://www.docswell.com/s/ystkfujii/57R9QW-2025-01-28-232244

## TL;DR

- トレースのLatencyは、トレースの処理時間ではなく、Observationの処理時間をもとにLatencyが計算されるっぽい。

## Langfuse とは

Langfuseは、Open Source LLM Engineering Platform のひとつです[^1]。類似の製品として、[OpenLLMetry](https://www.traceloop.com/docs/openllmetry/introduction)や[LangSmith](https://www.langchain.com/langsmith)などがあります。

[^1]: https://langfuse.com/

Langfuseを活用することで、LLM Applicationの評価やプロンプト管理、トレースやメトリクスをもとにしたオブザーバビリティの支援が実現できます。このように、たくさん機能はあるのですが、LTでは、Langfuseのトレース機能に絞って発表させていただきました。

### トレースとは

発表の中では、トレースを「**LLMアプリケーションの一連のイベントをまとめたもの**」と説明しました。例えば、Langfuseの画面では、あるリクエストのイベントの連なりを下記資料の右に示すような形でグラフィカルに参照することができます。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/967883/426ad37f-8a9f-35a7-1700-013911008c30.png)

ここで使用したTraceの説明は、[オブザーバビリティ・エンジニアリング](https://www.oreilly.com/library/view/untitled/9784814400126/)で分散トレースの説明に登場する「一連のイベント」に、「LLMアプリケーションに特化」というニュアンスを加えたものになります[^4]。

[^4]: 勝手に定義してごめんなさいという気持ちがあるのですが、短い時間で説明可能なキレの良い定義が見つからず、やっちゃいました。何か良い参考文献あれば教えてください :bow:


少しややこしいんですがが、Langfuseのトレースは、OpenTelemetryの文脈のトレースとは異なるものを指しています[^2]。また、LLMアプリケーションに特化した仕様になっており、以下のようなデータ構造を持っています[^3]。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/967883/87d0fad5-361d-d8da-6bd8-0882c09e1153.png)

[^2]: ちょっと言いすぎかなーという不安の中で書いています。
[^3]: https://langfuse.com/docs/tracing-data-model

Observationと呼ばれるものがトレースに属し、ObservationがEventやSpan、Generataionなどの種類を持っています。詳細は上記リンクもとの説明を読んでみてください。

:::note info
トレースやObservationに関するテーブル定義もGitHubにあがってるので、合わせて確認してみると理解が深まるかもです！
- FYI: [database.svg](https://github.com/langfuse/langfuse/blob/v3.14.0/packages/shared/prisma/database.svg)
:::

## LTの趣旨

「第1回Langfuse Quiz大会」というタイトルを設定していました。「クイズ作ってきたんで皆でやりましょう！」という感じなんですが、実は裏テーマとして下記Issueの完全理解がありました。

https://github.com/langfuse/langfuse/issues/4773

私自身が上記のIssueを読んでいて面白かったので、ぜひ皆さんと共有したいという思いで、関連する動作をクイズという形式で発表させていただきました。

### どんなIssueなのか

下記のプログラムを実行した際に、Langfuseで確認できるLatencyがCase#1とCase#2で異なるというIssueです。

```python: Case#1
@observe()
def hello_world():
    time.sleep(3)
    print("Hello World")

@observe()
def main():
    hello_world()

main()
```

```python: Case#2
@observe()
def hello_world():
    time.sleep(3)
    print("Hello World")

hello_world()
```

どちらも実行すると3秒ほど処理時間がかかるのですが、Langfuseの画面上で確認するLatencyは異なります。Case#1のLatencyは3秒と表示されますが、Case#2は0秒と表示されます。Case#2のLatencyも3秒ではないことに驚いた方もいるんじゃないでしょうか。実際、LTでクイズを出した際には、Case#2のLatencyを3秒と答えてる方も多かったです。

### 解説

なぜCase#2のLatencyが0秒となるのかは、下記のスライドで説明しています。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/967883/38e7cb7a-bff6-df91-d3a5-ecfd8709f4c4.png)

スライドだけだと何も分からないと思うので、補足します。前述した通り、Langfuseでは、トレースの中に関連するObservationが所属するデータモデルとなっています。Observationはその処理が始まった`start_time`と処理が終わった`end_time`の属性を持っていて、データベース上で永続化されています。あるトレースのLatencyはそのトレースに紐つくObservationの`start_time`と`end_time`の差で計算されます。そのため、Observationを持たないトレースのLatencyは計算することができないのです。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/967883/6d052f1c-2f37-7ca0-d2fe-df15fbd04458.png)

先ほどのCase#1は、TraceにObservationが属しているのでLatencyが計算可能でしたが、Case#2はObservationがなくTraceのみなのでLatencyが計算できず0秒となる。という挙動の違いが現れます。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/967883/9e190e68-062d-97c2-cf78-5db667de9fa5.png)

## LTで説明できなかった話

### Case#3

LTでは「Observationが無ければ、トレースのLatencyを計算できない」と説明しましたが、この表現であれば、「Observationがないトレースなんてレアなのでは？」と考える方もいるでしょう。別の言い方をすると「トレースのLatencyにはトレースの処理時間が考慮されない」とも表現できるので、Observationがない場合に限った話ではないです。

例えば、Case#1の`main`メソッドに`time.sleep(1)`を入れてみます。

```python: Case#3
@observe()
def hello_world():
    time.sleep(3)
    print("Hello World")

@observe()
def main():
    time.sleep(1)
    hello_world()

main()
```

実際に実行すると、処理に4秒ほどかかりますが、Langfuseの画面上ではLatencyは3秒と表示されます。この場合、Latencyの計算対象となるObservation（`hello_world`メソッド）の`start_time`と`end_time`の差が3秒なので、Langfuseの画面上でも3秒と表示されます。

なので、Observationが存在しない場合に限った話ではなく、意外と踏むかもしれない罠なのです。

### Case#4

@observeデコレータでは色々な属性を設定できます。Case#4は先ほどのCase#2で`as_type=generation`を指定したケースです。Case#2ではObservationが生成されずLatencyは0秒となりましたが、この場合はどうでしょうか？

```python: Case#4
@observe(as_type="generation")
def hello_world():
    time.sleep(3)
    print("Hello World")

hello_world()
```

Case#4の場合、Case#2と異なりLangfuseの画面上も3秒と表示されます。

`＠observe`デコレータの対象メソッドがTraceとObservationのどちらなのかは、LangfuseDecoratorクラスの[_prepare_callメソッド](https://github.com/langfuse/langfuse-python/blob/v2.58.0/langfuse/decorators/langfuse_decorator.py#L284)で判断されています。色々条件があるのですが、`as_type=generation`を指定してあげると、[L363-L375](https://github.com/langfuse/langfuse-python/blob/v2.58.0/langfuse/decorators/langfuse_decorator.py#L363-L375)の分岐に入ります。

```python: L363-L375
            elif as_type == "generation":
                # Create wrapper trace if generation is top-level
                # Do not add wrapper trace to stack, as it does not have a corresponding end that will pop it off again
                trace = self.client_instance.trace(
                    id=_root_trace_id_context.get() or id,
                    name=name,
                    start_time=start_time,
                )
                self._set_root_trace_id(trace.id)

                observation = self.client_instance.generation(
                    name=name, start_time=start_time, input=input, trace_id=trace.id
                )
```

ここでは、Traceが作成された後、Generation（Observation）が作成されるので、Latencyが計算可能になります。


## まとめ

[Langfuse Issue#4773](https://github.com/langfuse/langfuse/issues/4773)に関連した動作をLangfuse Night#1で紹介したケースに加えて、いくつか紹介しました。実際にコードを読んでみると自明なのですが、各Caseをパッと見ただけでは勘違いする場合もあるのではないでしょうか。執筆時点では、SaaS版のLangfuseでも同じ動作になるので、ぜひ実際に動かして試してみてください。

## P.S.

今回参加させて頂いたLangfuse Nigthですが、なんとLangfuse Night#2 が暖かくなった頃に開催されるらしいです！（いつだろう...春かな...）
今から楽しみですね

https://x.com/LangfuseJP/status/1884448693681815894