webhookを含むリクエスト間のdistributed tracingの設定

メリークリスマス！！Micoworksのyouchanです。
この記事はNew Relic 使ってみた情報をシェアしよう！ by New Relic Advent Calendar 2023の記事になります。
書きますと書いたきりついにクリスマスイヴイヴになってしまいました。m(_ _)m

MicoworksはLINEをメッセージングのチャネルとして利用するマーケティングツールのMicoCloudを開発・運営しています。私はメッセージング基盤の開発を担当しています。
MicoCloudでは大量のメッセージを送信したり、大量のユーザーからのメッセージを受けとったり、それを計測したりします。ユーザー数も増えてきたのでAPMを導入してメッセージングが恙無く行なわれているかモニタリングしようということでnewrelic APMの導入を進めています。

Problem

LINEからのメッセージを受けとるところに友達登録というフローがあります。LINEではユーザーに公式アカウントに友達登録をしてもらうことでメッセージを送ったりすることが出来るようになります。ですので友達登録というのは重要なフローになります。

ユーザーが友達登録するとLINEからwebhookが飛んできます。友達登録されたことはこのwebhookで知ることが出来ますがwebhookだけでは流入経路をトラッキングすることが出来ません。MicoCloudでは流入経路計測用にQRコードを作成してLIFFというLINEのミニアプリのページを挟むことで流入経路をトラッキングしています。

このフローではLIFFページからのAPI呼び出しとLINEからのwebhookの2つのリクエスト(図の3と6)が起ります。この2つのリクエストの間をDistributed tracingをつかって計測することが課題となります。
2つめのリクエストはLINEからのリクエストになるためtrace headerを埋めこむことが出来ません。このようなケースにどのように対応するのかについて解説したいと思います。

Solution

幸い、このフローはMicoCloudとしてもトレースする必要がありそのための仕組みがあります。2つのリクエストの間はcutomer_idというIDで紐付けられelastic cacheにコンテキストが保存されています。
このコンテキストを用いてdistributed tracingをする方法を考案しました。
ここではMicoCloudのソースコードを公開するわけにいかないので次のようなサンプルアプリケーションを仮定して説明します。

2つのエンドポイントを持つWebアプリケーションがあります。エンドポイントはそれぞれ、/parent,/childとします。
この2つのエンドポイントにはtracing headerを入れることは出来ないとします。
MicoCloudはnestjsで実装されていますのでnestjsでサンプルのアプリケーションをつくります。
(MicoWorksではTypeScriptをメインの言語に採用しています。我こそはというTypeScripterの方は是非一緒にアジアNo.1を目指すMicoworksにご応募ください。)

% nest new try-newrelic

newrelic APMを利用するための設定します。

app.controller.tsを編集して/parent,/childというエンドポイントを定義します。

@Get('/parent')
getParent(): string {
  return 'parent';
}

@Get('/child')
getChild(): string {
  return 'child';
}

それぞれ独立したトランザクションとしてAPMには記録されます。

distributed tracingを行なうためにはそれぞれのトランザクションからtrace headerをリクエストヘッダーを介さないで渡す必要があります。実アプリケーションではelastic cacheを使いますがここではインスタンス変数をもちいて渡すこととします。
app.contoller.tsを次のように書きかえます。

@Get('/parent')
async getParent(): Promise<string> {
  return await newrelic.startBackgroundTransaction('parent', async () => {
    const transaction = newrelic.getTransaction();
    this.newRelicTracingHeaders = {};
    transaction.insertDistributedTraceHeaders(this.newRelicTracingHeaders);
    newrelic.endTransaction();
    return 'parent';
  });
}

@Get('/child')
async getChild(): Promise<string> {
  return await newrelic.startBackgroundTransaction('child', async () => {
    const transaction = newrelic.getTransaction();
    transaction.acceptDistributedTraceHeaders('Parent', this.newRelicTracingHeaders);
    newrelic.endTransaction();
    return 'child';
  });
}

/parentと/childを順番にアクセスするとnewrelic APMのdistriubted tracingにはトランザクションが3つ表示されます。

通常のトランザクションの他にOtherTransaction/Nodejs/parentという名前のトランザクションがあります。これを開くと

APIによる処理が0.22ms(/parent)、0.20ms(/child)とその間に2.97sのなにもしていない区間があることが分かります。(この区間がユーザーの操作の間の時間になります。)