Azure Functions と Event Hubs の監視

Azure Event Hubs
Azure Functions
Azure Monitor

監視は、システムの動作と正常性に関する分析情報を提供し、環境の全体像の作成、過去の傾向の理解、さまざまな要因の関連付け、パフォーマンス、消費、エラー率の変化の測定に役立ちます。

Azure Functions には、Application Insights との統合機能が組み込まれています。 Application Insights では、関数アプリ インスタンスの数や、関数の要求および依存関係テレメトリなどの情報を取得できます。 Application Insights は、Functions および Event Hubs とともに使用すると、イベント ハブへの発信依存関係テレメトリを追跡することもできます。これにより、キューで費やされた時間を計算したり、Event Hubs を介して接続されたシステムのエンドツーエンド フローを示したりできます。

このセクションでは、Application Insights から取得できる、Event Hubs と Functions のソリューションに役立つ機能と分析情報について説明します。

アプリケーション マップ

アプリケーション マップは、システム内のコンポーネントが相互に対話する方法を示します。 Application Insights が提供する依存関係テレメトリにより、Azure Functions と Event Hubs の間のイベントのフローがマップ化されます。これには、各関数の実行の平均と Event Hubs 内のイベントの平均期間が含まれるとともに、赤色でマークされたエラーを含むトランザクションが示されます。

予想される負荷をシステムに送信した後、Azure portal で Application Insights に移動し、サイドバーで [アプリケーション マップ] を選択できます。 以下に、3 つの関数、3 つのイベント ハブ、およびダウンストリーム データベースへの書き込み時の明らかなエラーを示すマップを示します。

アプリケーション マップ

エンドツーエンド トランザクションの詳細

エンドツーエンドのトランザクションの詳細には、システム コンポーネントが相互にどのように対話するかが、時系列で示されます。 このビューには、イベントがキュー内で滞留した時間も表示されます。 また、このビューから各コンポーネントのテレメトリを詳細に確認できるため、問題が発生した場合に、同じ要求内のコンポーネント間のトラブルシューティングが容易になります。

エンドツーエンドのトランザクション

プラットフォーム メトリックとテレメトリ

Event Hubs および Azure Functions 用の Azure Monitor のプラットフォーム生成メトリックは、ソリューションの動作と正常性の全体的な監視のために次のように使用できます。

  • Azure Monitor の Azure Event Hubs メトリックは、Event Hubs に役立つ分析情報 (受信要求数、送信要求数、調整された要求数、成功した要求数、受信メッセージ数、送信メッセージ数、キャプチャされたメッセージ数、受信バイト数、送信バイト数、キャプチャされたバイト数、ユーザー エラー数の集計など) をキャプチャするために有用です。

  • Azure Functions のメトリックは、Azure App Service とメトリックの多くを共有しています。また、従量課金プランの使用量とコストを理解するために使用できる関数の実行回数と関数の実行単位が追加されています。 その他の重要なメトリックとして、接続数、受信データ、送信データ、平均メモリ ワーキング セット、スレッド数、要求数、応答時間があります。

Azure Functions を Application Insights と統合することで、Functions のホストと関数の実行に関する高度で詳細なテレメトリと分析情報を提供できます。 詳細については、「Application Insights で Azure Functions のテレメトリを分析する」を参照してください。 Application Insights を使用してトポロジを監視する場合、さまざまな構成を使用できます。 詳しくは、Azure Functions で監視を構成する方法に関するページを参照してください。

以下に、トレース テーブルで生成される、Event Hubs でトリガーされる関数のもう 1 つのテレメトリの例を示します。

Trigger Details: PartionId: 6, Offset: 3985758552064-3985758624640, EnqueueTimeUtc: 2022-10-31T12:51:58.1750000+00:00-2022-10-31T12:52:03.8160000+00:00, SequenceNumber: 3712266-3712275, Count: 10

この情報を取得するには、4.2.0 以降のバージョンの Event Hubs 拡張機能を使用する必要があります。 このデータは、関数の実行をトリガーしたメッセージに関する情報が含まれているため非常に有用であり、クエリや分析情報に使用できます。 これには、関数がトリガーされるたびに次のデータが含まれます。

  • パーティション ID (6)
  • パーティション オフセットの範囲 (3985758552064-3985758624640)
  • エンキュー時間の範囲 (UTC) (2022-10-31T12:51:58.1750000+00:00-2022-10-31T12:52:03.8160000+00:00)
  • シーケンス番号の範囲 3712266-3712275
  • メッセージの数 (10)

このテレメトリの使用方法の例については、「Application Insights クエリの例」のセクションを参照してください。

カスタム テレメトリは、異なる言語 (C# クラス ライブラリC# IsolatedC# スクリプトJavaScriptJavaPowerShellPython) にも対応しています。 このログは、Application Insights のトレース・テーブルに表示されます。 Application Insights に独自のエントリを作成し、データのクエリやカスタム ダッシュボードの作成に使用できるカスタム ディメンションを追加できます。

最後に、関数アプリが出力バインディングを使用してイベント ハブに接続すると、エントリは Application Insights の依存関係テーブルにも書き込まれます。

依存関係テーブル

Event Hubs では、関連付けがイベント ペイロードに挿入され、以下のように Diagnostic-Id プロパティがイベントに表示されます。

Diagnostic-Id プロパティ

これは、Functions によって作成されるテレメトリ内で操作 ID および操作リンクとしても使用される W3C トレース コンテキストの形式に従っています。これにより、Application Insights では、イベント ハブのイベントと関数実行が分散されている場合でも、それらの間に関連付けを構築できます。

バッチ イベントの関連付け

Application Insights クエリの例

以下に、Azure Functions を使用して Event Hubs を監視するときに役立つ Application Insights クエリをリストします。 このクエリは、Event Hubs 拡張機能 4.2.0 以上によって出力されたテレメトリを使用して、イベント ハブによってトリガーされる関数の詳細情報を表示します。

Application Insights でサンプリングを有効にすると、データにギャップが生じる場合があります。

詳細なイベント処理情報

データが正しい形式で出力されるのは、バッチ ディスパッチが使用されている場合のみです。 バッチ ディスパッチは、関数が実行ごとに複数のイベントを受け入れることを意味し、パフォーマンス上の観点から推奨されています。 次の考慮事項に留意してください。

  • dispatchTimeMilliseconds 値は、イベントがイベント ハブに書き込まれた時刻から、処理のために関数アプリによって取得された時刻までのおおよその時間の長さを表します。
  • dispatchTimeMilliseconds は、イベント ハブ サーバーと関数アプリの間のクロック ドリフトが原因で、負の値になったり不正確になったりする可能性があります。
  • Event Hubs のパーティションは順番に処理されます。 あるメッセージが処理のために関数コードにディスパッチされるのは、前のメッセージがすべて処理されてからです。 実行時間が長くなるとディスパッチの遅延が発生するため、関数の実行時間を監視してください。
  • 計算では、バッチ内の最初のメッセージの enqueueTime が使用されます。 バッチ内の他のメッセージでは、ディスパッチ時間が短くなる可能性があります。
  • dispatchTimeMilliseconds は、特定の時点に基づいています。
  • シーケンス番号はパーティション単位です。Event Hubs では厳密に 1 回のメッセージ配信が保証されていないため、重複する処理が発生する可能性があります。
traces
| where message startswith "Trigger Details: Parti"
| parse message with * "tionId: " partitionId:string ", Offset: "
offsetStart:string "-" offsetEnd:string", EnqueueTimeUtc: "
enqueueTimeStart:datetime "+00:00-" enqueueTimeEnd:datetime "+00:00, SequenceNumber: "
sequenceNumberStart:string "-" sequenceNumberEnd:string ", Count: "
messageCount:int
| extend dispatchTimeMilliseconds = (timestamp - enqueueTimeStart) / 1ms
| project timestamp, cloud_RoleInstance, operation_Name, processId =
customDimensions.ProcessId, partitionId, messageCount, sequenceNumberStart,
sequenceNumberEnd, enqueueTimeStart, enqueueTimeEnd, dispatchTimeMilliseconds

詳細なイベント処理

ディスパッチ待機時間の視覚化

このクエリは、特定のイベント ハブによってトリガーされる関数の 50 番目と 90 番目のパーセンタイルのイベント ディスパッチ待機時間を視覚化します。 詳細と注意事項については、上記のクエリを参照してください。

traces
| where operation_Name == "<ENTER THE NAME OF YOUR FUNCTION HERE>"
| where message startswith "Trigger Details: Parti"
| parse message with * "tionId: " partitionId:string ", Offset: "
offsetStart:string "-" offsetEnd:string", EnqueueTimeUtc: "
enqueueTimeStart:datetime "+00:00-" enqueueTimeEnd:datetime "+00:00, SequenceNumber: "
sequenceNumberStart:string "-" sequenceNumberEnd:string ", Count: "
messageCount:int
| extend dispatchTimeMilliseconds = (timestamp - enqueueTimeStart) / 1ms
| summarize percentiles(dispatchTimeMilliseconds, 50, 90) by bin(timestamp, 5m)
| render timechart

ディスパッチ待機時間の視覚化

ディスパッチ待機時間の概要

このクエリは上記と似ていますが、概要ビューが表示されます。

traces
| where message startswith "Trigger Details: Parti"
| parse message with * "tionId: " partitionId:string ", Offset: "
offsetStart:string "-" offsetEnd:string", EnqueueTimeUtc: "
enqueueTimeStart:datetime "+00:00-" enqueueTimeEnd:datetime "+00:00, SequenceNumber: "
sequenceNumberStart:string "-" sequenceNumberEnd:string ", Count: "
messageCount:int
| extend dispatchTimeMilliseconds = (timestamp - enqueueTimeStart) / 1ms
| summarize messageCount = sum(messageCount),
percentiles(dispatchTimeMilliseconds, 50, 90, 99, 99.9, 99.99) by operation_Name

ディスパッチ待機時間の概要

パーティション間でのメッセージの分散

このクエリでは、パーティション間でのメッセージの分散を視覚化する方法を示します。

traces
| where message startswith "Trigger Details: Parti"
| parse message with * "tionId: " partitionId:string ", Offset: "
offsetStart:string "-" offsetEnd:string", EnqueueTimeUtc: "
enqueueTimeStart:datetime "+00:00-" enqueueTimeEnd:datetime "+00:00, SequenceNumber: "
sequenceNumberStart:string "-" sequenceNumberEnd:string ", Count: "
messageCount:int
| summarize messageCount = sum(messageCount) by cloud_RoleInstance,
bin(timestamp, 5m)
| render areachart kind=stacked

パーティション間でのメッセージの分散

インスタンス間でのメッセージの分散

このクエリでは、インスタンス間でのメッセージの分散を視覚化する方法を示します。

traces
| where message startswith "Trigger Details: Parti"
| parse message with * "tionId: " partitionId:string ", Offset: "
offsetStart:string "-" offsetEnd:string", EnqueueTimeUtc: "
enqueueTimeStart:datetime "+00:00-" enqueueTimeEnd:datetime "+00:00, SequenceNumber: "
sequenceNumberStart:string "-" sequenceNumberEnd:string ", Count: "
messageCount:int
| summarize messageCount = sum(messageCount) by cloud_RoleInstance,
bin(timestamp, 5m)
| render areachart kind=stacked

インスタンス間でのメッセージの分散

実行中のインスタンスと割り当てられたインスタンス

このクエリでは、Event Hubs のイベントを処理している Azure Functions インスタンスの数と、インスタンスの総数 (処理中のものとリースを待機中のもの) を視覚化する方法を示します。 ほとんどの場合、これらは同じになるはずです。

traces
| where message startswith "Trigger Details: Parti"
| summarize type = "Executing Instances", Count = dcount(cloud_RoleInstance) by
bin(timestamp, 60s)
| union (
    traces
    | summarize type = "Allocated Instances", Count = dcount(cloud_RoleInstance) by
bin(timestamp, 60s)
)
| project timestamp, type, Count
| render timechart

実行中のインスタンスと割り当てられたインスタンス

特定の関数実行のすべてのテレメトリ

[operation_Id] フィールドは、Application Insights の異なるテーブルで使用できます。 Event Hubs でトリガーされる Azure Functions の場合、たとえば、以下のクエリにより、トリガー情報、Function コード内のログからのテレメトリ、依存関係と例外が取得されます。

union isfuzzy=true requests, exceptions, traces, dependencies
| where * has "<ENTER THE OPERATION_ID OF YOUR FUNCTION EXECUTION HERE>"
| order by timestamp asc

特定の関数実行のすべてのテレメトリ

イベントのエンドツーエンド待機時間

トリガーの詳細トレースの enqueueTimeUtc プロパティは、関数で処理された各バッチの最初のイベントのエンキュー時間のみを示すので、より高度なクエリを使用して、Event Hubs が間に存在する 2 つの関数間のイベントのエンドツーエンド待機時間を計算できます。 このクエリは、2 番目の関数の要求で操作リンク (存在する場合) を展開し、その終了時刻を最初の関数の開始時刻の対応する同じ操作 ID にマップします。

let start = view(){
requests
| where operation_Name == "FirstFunction"
| project start_t = timestamp, first_operation_Id = operation_Id
};
let link = view(){
requests
| where operation_Name == "SecondFunction"
| mv-expand ex = parse_json(tostring(customDimensions["_MS.links"]))
| extend parent = case(isnotempty(ex.operation_Id), ex.operation_Id, operation_Id )
| project first_operation_Id = parent, second_operation_Id = operation_Id
};
let finish = view(){
traces
| where customDimensions["EventName"] == "FunctionCompleted" and operation_Name
== "SecondFunction"
| project end_t = timestamp, second_operation_Id = operation_Id
};
start
| join kind=inner (
link
| join kind=inner finish on second_operation_Id
) on first_operation_Id
| project start_t, end_t, first_operation_Id, second_operation_Id
| summarize avg(datetime_diff('second', end_t, start_t))

イベントのエンドツーエンド待機時間

共同作成者

この記事は、Microsoft によって保守されています。 当初の寄稿者は以下のとおりです。

プリンシパル作成者:

  • David Barkol | プリンシパル ソリューション スペシャリスト (GBB)

パブリックでない LinkedIn プロファイルを表示するには、LinkedIn にサインインします。

次のステップ

詳細については、次の関連記事を確認してください。