【失敗と対策】Azure Functions で Application Insights を使用する際の注意点

2021年11月4日 18:40

こんにちは、アバナード関西オフィス）篠田です。
業務で Azure Functions (以下、Functions) をインフラ担当として触る機会があって、ちょっとハマった落とし穴があるんですが、社内で失敗談として共有したところ、意外とその落とし穴について知らない人はいそうな感じでした。
今回はその失敗について、備忘録として残そうかと思います。
忙しい方は目次を見て、知らない情報だったら詳細覗いてみてください。

対象の Functions：Application Insights を利用

この失敗談は、Application Insights でテレメトリ収集をしている全ての Functions にて(デフォルト設定だと)起こりえる事象になります。

私の担当したシステムの Functions では、HTTP トリガーを使用し、クライアントアクセスに応じて動作する API がアプリ担当者によって実装されていました。

また、Log Analytics ワークスペースにプラットフォームとしてのメトリック・ログを収集するのに加えて、アプリチームの詳細なアプリケーションパフォーマンス管理（APM）を可能にするため、Application Insights をデプロイし、テレメトリの収集も実施していました。

絵にすると、簡単ですが下図のような感じです。

システム概要図

事象：エラーログのロスト

一言で言うと、Application Insights で収集されるべきテレメトリであるエラーログの一部をロストしました。

事象が発生したのは、システム構築も概ね完了し、アプリチーム主導でシステムのパフォーマンステストを実施した時です。

それまでかかった事のない負荷が Functions にかかり、インスタンスのスケールアウトが発生したんですが、そのスケールアウトのタイミングで、関連する Azure サービスの仕様に起因するエラーが Functions にて発生しました。
（このエラーについては話すと長いので省略します、現在は解決済みです）

パフォーマンステストが終わった後、

アプリ担当者：Application Insights を見て結果を確認
インフラ担当者(私)：Log Analytics ワークスペースで結果を確認

という役割分担で結果の考察を進めてたんですが、

アプリ「HTTP 500 コードのサーバーエラーが沢山出てますねー」

インフラ「ホントですね、80件も出てますねー」

ア「え？こっちでは60件しか出てないですよ。」

イ「え！？」

こんな感じになりました。

原因：テレメトリのサンプリングが既定でオン

原因は、Application Insights にて収集されるテレメトリについて、サンプリング（間引き）が発生していたからでした。

サンプリングにもいくつか種類がありますが、今回適用されたサンプリングは、アダプティブサンプリングという種類でした。

アダプティブサンプリングは、Application Insights ASP.NET および ASP.NET Core ソフトウェア開発キット (SDK) のすべての最新バージョンで既定で有効になっています。また、Azure Functions でも使用されます。

Application Insights の有効化は Functions で実施したものの、特にデフォルト設定から変更していなかったので、アダプティブサンプリングが既定でオンになってました。

アダプティブサンプリングでは、ASP.NET/ASP.NET Core アプリの SDK および Azure Functions から送信されるテレメトリの量が自動的に調整されます。

公式ドキュメントには細かい仕様についても記載がありますが…要するに、テレメトリの収集量が多くなった時は勝手に間引かれますよ、という状態になっていたようです。

なお、過去にテレメトリのログについてサンプリングが発生していたかどうかは、対象の Application Insights リソースをスコープにして、以下のログクエリを実行することで確認できます。
※確認対象の時間範囲は別途ポータル画面やログクエリ内で指定が必要。

union traces, requests, customEvents, dependencies, exceptions 
| summarize count(), sum(itemCount), percentageretained = (((count() * 1.0 / sum(itemCount) * 1.0) * 100.0)) by itemType 
| project TelemetryType = itemType, RawRecordCount = count_, ItemCount = sum_itemCount, Percentage = percentageretained

このクエリで得られる Percentage の値が 100 でない場合は、その100%に満たない分だけ、対象のテレメトリでログのサンプリングが発生したことを示します。
私の担当システムのパフォーマンステスト時間帯では見事に、trace が30%未満、request が70%未満になってました…そんなに間引かれちゃうという事実にビックリしました…

サンプリングは Azure Application Insights の機能です。アプリケーションデータの分析に関して統計的な正しさを保ちながら、テレメトリのトラフィック、データコスト、およびストレージコストを削減する方法として推奨されます。

との事ですが、私の担当システムでは、漏れなくテレメトリが収集される事が、クライアントリクエストのトレーサビリティとして必須要件だったため、修正が必要になりました。

解決策：サンプリングの無効化

解決策として、Functions の wwwroot にある host.json を修正し、Application Insights のデフォルト設定を上書きしてサンプリングを無効化しました。

{
    "logging": {
        "applicationInsights": {
            "samplingSettings": {
                "isEnabled": false
            }
        }
    }
}

上記のパラメータを host.json に追加する（既存でパラメータがある場合は書き換える）ことで、サンプリングを無効化しました。
私の担当システムでは wwwroot 配下のコード管理・デプロイは全てアプリ担当者に一任されていたので、実際はお願いして修正していただきました、快く引き受けてくださったアプリ担当者に感謝です。

なお、上記の対処でサンプリングの無効化が確かに出来ているかを、ポータル画面やコマンド出力で確認する術がないか、Microsoft サポートに問い合わせたのですが、残念ながら現状無いそうです。
なので先述のログクエリの結果から、サンプリングが起こっていない、という後追いの確認をするしかなく、設定時点では「ただお守りをつけただけ」みたいな気持ちでしたが、無事サンプリングは発生しなくなりました、めでたし。

まとめ：失敗を通じて思ったこと

今回、個人的に得た教訓は、以下3点です。

①導入する機能のデフォルト仕様は可能な限り確認すべし

②それでも漏れはあるからテストも可能な限り網羅的にすべし

③システム内で担当が分かれている場合は協力を密にすべし

ただ、①、②は時間に制約がある中で仕事している関係上、どうしてもやり切れない場合は実際問題あります。

結構③が肝な気がしますね。

今回は、Functions のテンプレートの HTTP トリガーに対してF5連打したものの、ちっともCPU使用率が上がらず自動スケーリングの動作テストが出来なかったので、

「アプリチーム主導のパフォーマンステストではなるべく負荷かけてスケールアウトを発生させてほしい。その代わりテスト後の結果確認は一緒にやるから。」

と、インフラチームからアプリチームにお願いしてて、パフォーマンステストに対する協力関係が事前に築けていたので、スケーリング時のエラーにも気付けたし、設定ミスによる Application Insights のログのロストにも気付けました。

システム構築をある程度の人数でやっていると、どうしても役割分担とか責任分界点の話になりがちで、どこまで細かく区切っても結局グレーゾーンって出てきますよね。

それなら、

「管理都合上、分担決めて進めるけど、困ったときは助けあいましょうね」

っていう気持ちで仕事出来た方が個人的には気が楽だし、良い効果も生まれやすいのではないかと思いました。

この記事が皆さんのお役に立てましたらいいねやフォローをお願いします。
内容に関するご指摘や、その他何かございましたら下記に連絡ください。
アバナード関西オフィス　篠田　諭
satoshi.shinoda(@)avanade.com

[会社紹介]最近 Wantedly にアバナード関西オフィスについて記事が掲載されました！

この記事が気に入ったらサポートをしてみませんか？