[update] Amazon CloudFrontのリアルタイムログにより詳細なインサイトが可能になる3つのフィールドが追加されています

CloudFrontのリアルタイムログでオリジンサーバから最初と最後のバイトが返されるまでの応答時間、ならびにクライアントのASNが格納されるフィールドが追加されました。ASNについてはCloudFrontヘッダでも確認可能となっています。

#Amazon CloudFront

#AWS

清水俊也

2022.11.30

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

はじめに

清水です。AWS re:Invent 2022開催中だけどre:Invent前に発表されたアップデートもしっかりおさえておこうのコーナーです。本エントリでお届けするアップデートはこちら！AWSのCDNサービスであるAmazon CloudFrontでリアルタイムログに新たに3つのフィールドが追加されました。（2022/10/20付でAWS What's Newにポストされたアップデート情報となります。）

CloudFrontのリアルタイムログに新たに追加されたフィールドはOrigin first-byte latency、Origin last-byte latency、ASN（autonomous system number、AS番号）の3つです。Origin first-byte latencyとOrigin last-byte latencyはそれぞれ、その名の通りオリジンから最初もしくは最後のバイトを返す応答時間を秒単位で示したものとなります。ASNはクライアント（CloudFrontでいうViewer）のネットワークを識別する固有の番号で、クライアントのISPなどによって異なるものですね。これら3つのフィールドを活用することで、例えば特定のISP環境下ではパフォーマンスが低下している、といったCloudFrontのパフォーマンスに関するより詳細なインサイトが可能になります。

本エントリでは、この新たに追加された3つのフィールドについて、実際にCloudFrontにリアルタイムログを設定しながら確認してみました。あわせて、CloudFrontで利用できるヘッダにクライアントのASNが格納されるCloudFront-Viewer-ASNがいつの間にか追加されていたので、こちらについても簡単ですが確認しています。

CloudFrontでリアルタイムログ確認のためのリソース準備

まずはCloudFrontでリアルタイムログを確認するため、ログ発生もととなるディストリビューションならびに、リアルタイムログを出力するための各種リソースを準備していきます。CloudFrontのリアルタイムログはKinesis Data Streamsと連携するかたちです。また今回はKinesis Data StreamからKinesis Data Firehoseに連携し、S3バケット内にログファイルとして保存するかたちとしました。（標準のアクセスログとあまり変わりないような感じですが、目的が「リアルタイムログ自体を確認すること」であるためこれで進めます。）

以下のブログエントリやAWSドキュメントなどを参考にしつつ、これら関連リソースの準備を進めていきます。

リアルタイムログ出力をサポートしたCloudFrontを試してみた | DevelopersIO

なお、CloudFront以外の関連リソースとしてS3バケット、Kinesis Data Streams、Kinesis Data Firehoseとリソースを作成していますが、いずれも東京リージョンに作成しました。（ACM証明書などCloudFront関連のリソースはバージニアリージョンである必要がある、という制約がある場合もありますが、リアルタイムログ設定に関する項目（特にKinesi Data Stream）についてはバージニアリージョン以外でも動作はするようです。）

リアルタイムログを最終的に保存するS3バケット

最終的なリアルタイムログ保存先となるS3バケットを新たに作成しておきました。S3バケット作成時のオプションで、デフォルトの暗号化だけSSE-S3を使用するように変更しておきました。ほかの項目はすべてデフォルトとしています。（標準アクセスログではまだ有効化が必要なACLについても、リアルタイムログ保存用なので無効としています。）

CloudFrontからのリアルタイムログ出力先となるKinesis Data Streams

続いてはKinesis Data Streamsのリソースの準備です。Kinesisのマネジメントコンソール、データストリームの画面から[データストリームの作成]ボタンで進みます。

データストリーム名を指定し、データストリーム容量の容量モードについては、今回はオンデマンドを選択してみました。データストリーム設定を確認して[データストリームの作成]ボタンを押下します。

データストリームが作成できました。

データストリムをS3に出力先するためのKinesis Data Firehose

データストリームの準備ができたら、続いてKinesis Data Firehoseの配信ストリームを作成します。作成したデータストリームの画面、アプリケーションタブのコンシューマー、Amazon Kinesis Data Firehoseの[配信ストリームを使用した処理]ボタンから進みます。

配信ストリーム作成画面、ソースと送信先を選択の項目です。ソースはデフォルトのAmazon Kinesis Data Streamsのまま、送信先としてAmazon S3を選択します。

「ソースの設定」以降の設定項目が現れます。ソースの設定では先ほど作成したデータストリームが指定されていることを確認します。

「配信ストリーム名」はデフォルトでKDS-S3-8JJywという名称が付与されていました。最後5文字はランダムな文字列かと思います。わかりやすくなるようKDS-S3-CFRTLとしておきました。「レコードを変換および転換」の項目はデフォルト（いずれも無効）のまま進めます。

「送信先の設定」で先ほど作成したS3バケットを指定します。その他の項目はデフォルトとしました。（実際はここでS3バケットプレフィックスなどを適切に設定するようにしましょう。）

最後の「詳細設定」の項目もデフォルトのままとしました。[配信ストリームを作成]ボタンを押下します。

配信ストリームが作成できました。

リアルタイムログを有効にするCloudFrontディストリビューション

リアルタイムログ取得対象となるCloudFrontディストリビューションを、リアルタイムログ設定に先行して作成しておきます。今回、オリジンサーバにはApache HTTP ServeとPHPが動作しているEC2インスタンスを準備しました。以下のindex.phpのコードを配置しています。ルートドキュメント（/）にアクセスすると3秒後にアクセス時のヘッダ内容を返す、というぐあいです。（3秒はダウンロード時間をイメージしました。）

<?php

foreach (getallheaders() as $name => $value) {
    echo "<p>";
    echo "$name: $value";
    echo "</p>\n";
}

sleep(3);
echo "<p></p>\n"

?>

CloudFrontディストリビューション作成の詳細については省略します（基本的にはデフォルト設定で進めました）が、キャッシュ設定まわりだけ記載しておきます。今回はキャッシュ設定としてLegacy cache settingsを使用しました。ヘッダ、クエリ文字列、Cookieのすべてを転送するよう設定しています。

ディストリビューションが作成できました。

CloudFrontにリアルタイムログを設定

関連リソースが作成できたので、実際にCloudFrontにリアルタイムログを設定していきます。リアルタイムログ設定を作成し、それをディストリビューションのビヘイビアに関連付ける、という手順となります。（ビヘイビア側の設定でも行えますが、今回はリアルタイムログ設定の画面から設定を行いました。）

CloudFrontのマネジメントコンソール、テレメトリーの「ログ」、「リアルタイム設定」タブの[設定を作成]ボタンから進みます。設定の名前を入力、サンプリングレートは今回検証目的でありアクセス数も少ない想定ですので100%としました。すべてのアクセスをリアルタイムログに記録するかたちですね。フィールドについて、今回はすべての項目をDeveloper Guide記載の順で設定していきました。（なかなかしんどかったですw）なお今回のアップデート対象となっているのは最後の3つ、origin-fbl、origin-lbl、asnとなります。

エンドポイントには先ほど作成したデータストリームを指定します。IAMロールは新しく作成しました。

設定ができました。この段階ではまだCloudFrontディストリビューション側はデプロイ中の状態ですので、「アタッチされたディストリビューション」についてはステータスが「無効」となっています。しばらくすると（ディストリビューション側で有効になると）こちらのステータスも有効となります。

新たにリアルタイムログに追加された3つのフィールドを確認してみる

前置きとなるリアルタイムログ確認のためのリソース準備が長くなってしまいましたが、CloudFrontのリアルタイムログを確認する準備が整いました。リアルタイムログを設定したCloudFrontディストリビューションのデプロイが完了したら、このディストリビューションドメイン名にWebブラウザからアクセスしてみます。ページを開くと3秒ほど待機したあと、以下のようにリクエストヘッダ内容が表示されます。（この3秒の待機についてはオリジンサーバ側PHPファイルに設定したものですね。）

リアルタイムログが保存されるS3バケットについても確認してみましょう。Kinesis Data StreamsとKinesis Data Firehoseの連携もありアクセス後即座にファイルが作成されるわけではありませんが、数分もするとS3バケットにログファイルが書き込まれます。

実際にいくつかのバリエーションでアクセスしたあと、ログファイルの中身を確認してみましょう。S3バケット内のファイルをそのままAmazon Athenaなどで分析することも可能ですが、今回はシンプルにS3からローカル環境にダウンロードしてテキストベースで確認していきます。

まずは以下コマンド形式でローカル環境にダウンロードします。（参考: [小ネタ] S3に保存されているログファイルをAWS CLIでまとめてコピーする | DevelopersIO）

% aws s3 cp s3://cloudfront-realtimelogs-XXXX/2022/11/30/08/ .  --recursive --exclude "*" --include "KDS-S3-CFRTL*"

以下のようなレコードとなっています。（1レコードのみ抜粋しつつ、フィールドの区切り文字となるタブを改行に置換しています。）

1669806836.017
24xx:xx:xxxx:xxxx:xxxx:xxxx:xxxx:xx20
3.026
200
1014
GET
https
d3phxxxxxxxxxx.cloudfront.net
/
25
NRT12-C4
dA6sxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxTA==
d3phxxxxxxxxxx.cloudfront.net
3.026
HTTP/2.0
IPv6
Mozilla/5.0%20(Macintosh;%20Intel%20Mac%20OS%20X%2010_15_7)%20AppleWebKit/537.36%20(KHTML,%20like%20Gecko)%20Chrome/107.0.0.0%20Safari/537.36
-
-
-
Miss
-
TLSv1.3
TLS_AES_128_GCM_SHA256
Miss
-
-
text/html;%20charset=UTF-8
-
-
-
65022
Miss
JP
gzip,%20deflate,%20br
text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9
*
host:d3phxxxxxxxxxx.cloudfront.net%0Asec-ch-ua:%22Google%20Chrome%22;v=%22107%22,%20%22Chromium%22;v=%22107%22,%20%22Not=A?Brand%22;v=%2224%22%0Asec-ch-ua-mobile:?0%0Asec-ch-ua-platform:%22macOS%22%0Aupgrade-insecure-requests:1%0Auser-agent:Mozilla/5.0%20(Macintosh;%20Intel%20Mac%20OS%20X%2010_15_7)%20AppleWebKit/537.36%20(KHTML,%20like%20Gecko)%20Chrome/107.0.0.0%20Safari/537.36%0Aaccept:text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9%0Asec-fetch-site:none%0Asec-fetch-mode:navigate%0Asec-fetch-user:?1%0Asec-fetch-dest:document%0Aaccept-encoding:gzip,%20deflate,%20br%0Aaccept-language:ja,en-US;q=0.9,en;q=0.8%0ACloudFront-Is-Mobile-Viewer:false%0ACloudFront-Is-Tablet-Viewer:false%0ACloudFront-Is-SmartTV-Viewer:false%0ACloudFront-Is-Desktop-Viewer:true%0ACloudFront-Viewer-Country:JP%0A
host%0Asec-ch-ua%0Asec-ch-ua-mobile%0Asec-ch-ua-platform%0Aupgrade-insecure-requests%0Auser-agent%0Aaccept%0Asec-fetch-site%0Asec-fetch-mode%0Asec-fetch-user%0Asec-fetch-dest%0Aaccept-encoding%0Aaccept-language%0ACloudFront-Is-Mobile-Viewer%0ACloudFront-Is-Tablet-Viewer%0ACloudFront-Is-SmartTV-Viewer%0ACloudFront-Is-Desktop-Viewer%0ACloudFront-Viewer-Country%0ACloudFront-Forwarded-Proto%0ACloudFront-Viewer-ASN%0A
20
3.010
3.010
2xx6

すべてのフィールドがある状態で確認するのはなかなかつらかったので、見やすくするようにawkで加工します。ViewerのIPアドレス（クライアントIP）、Request ID（x-amz-cf-idヘッダと同じ値）、そして今回のアップデート対象となるOrigin first-byte latency、Origin last-byte latency、ASNのみを選択しました。awk -F "\t" '{print $2,$12,$41,$42,$43;}'というぐあいです。またRequest IDについては一部をマスクしつつ短くなるよう省略しています。

24xx:xx:xxxx:xxxx:xxxx:xxxx:xxxx:xx20 dA6sxxxxxxxxTA== 3.010 3.010 2xx6
49.xxx.xxx.151 xio2xxxxxxxx-A== 3.006 3.007 9xx5
24xx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xx05 JHysxxxxxxxxBg== 3.009 3.009 17xxx
2axx:xxxx:xxxx:xx::xx:xb rv72xxxxxxxxEg== 3.017 3.017 0

まずはOrigin first-byte latencyとOrigin last-byte latencyについて確認します。オリジン側のレスポンスで3秒の待機時間を設けたので、first-byteからlast-byteまで3秒かかる動作が確認できれば、と思ったのですが。これはPHP側で3秒経過後、まとめてレスポンスを返しているようですね。first-byteからlast-byteまでの値はほぼ同じ値となりました。2つ目のリクエストだけ、0.001秒の違いが確認できるといったぐあいです。実際にこのfirst-byteからlast-byteのlatencyの違いが聞いてくるのは、容量の大きなファイルを断続的に配信するような場合なのかな、などと考えています。

続いてASNについてです。実はCloudFront HTTPヘッダにもASNを示すCloudFront-Viewer-ASNというヘッダが追加されていました。（追加時期などの詳細については後述します。）Webブラウザでアクセスした結果表示されるこのCloudFront-Viewer-ASNと、該当するリアルタイムログのレコードをそれぞれ確認していきましょう。

まず先ほどディストリビューションドメインにアクセスした結果のスクショを再掲します。こちらに相当するリアルタイムログのレコードが下記です。（リアルタイムログはawkで一部抜粋したものとなります。）こちらは私がいつも利用している、某プロバイダのv6プラスの自宅インターネット回線です。ASNは2xx6という値でした。

24xx:xx:xxxx:xxxx:xxxx:xxxx:xxxx:xx20 dA6sxxxxxxxxTA== 3.010 3.010 2xx6

続いて、NTTドコモ回線でテザリングを行った場合です。ASNは9xx5でした。インターネットプロバイダが変わるとASNも変わることが確認できますね。

49.xxx.xxx.151 xio2xxxxxxxx-A== 3.006 3.007 9xx5

もう一つテザリングで、今度はSoftbank回線です。ASNは17xxxという値でした。

24xx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xx05 JHysxxxxxxxxBg== 3.009 3.009 17xxx

ところで、弊社クラスメソッドではCloudflare Zero Trustを導入しています。こちらを有効にした環境下でも確認してみました。ASNについては0となりました。ASNについて0は使用が禁止されている、ということで、VPN環境下では正確なASNが取得できないのでは、などと推測しています。（参考: 自律システム (インターネット) - Wikipedia）

2axx:xxxx:xxxx:xx::xx:xb rv72xxxxxxxxEg== 3.017 3.017 0

CloudFront-Viewer-ASNヘッダについて

リアルタイムログに記載されるようになったOrigin first-byte latency、Origin last-byte latency、ASNの各フィールドを確認してきました。その中でASNの確認方法として、CloudFront-Viewer-ASNヘッダも利用できることに触れました。このCloudFront-Viewer-ASNヘッダのサポート、特にアップデート情報はなかったかと思いますが、いつの間にか利用可能なCloudFront HTTPヘッダに追加されていました。

2022/11/30現在、英語版のドキュメントには記載がある状況となっています。

Adding the CloudFront HTTP headers - Amazon CloudFront

本ブログエントリで扱ったように、Legacy cache settingsですべてのヘッダを転送するよう設定した場合のほか、Origin request policyでも利用可能です。

（なお、Internet Archive Wayback Machineを確認してみると、2022/09/29の段階では記載がなく、次のバージョンとなる2022/11/21の段階で記載されていた、という状況でした。ただ、2022/06末ごろに表示されていた、なんて情報もあるのですが。）

まとめ

CloudFrontのリアルタイムログで新たに追加された3つのフィールド、Origin first-byte latency、Origin last-byte latency、そしてASNについて、実際にCloudFrontにリアルタイムログ設定をしながら確認してみました。これらの値を使ってすぐに何かを設定する、といったものではないのですが、AWS What's NewのタイトルのとおりCloudFrontのパフォーマンスに対するより詳細なインサイトを得るために活用ができるかと思います。これら3つのフィールドについては、いずれも標準ログではサポートされておらずリアルタイムログのみで利用可能な点についても抑えておきましょう。またいつの間にかサポートされていたCloudFront-Viewer-ASNヘッダについても簡単に確認してみました。