ロギングを担当するCloud FoundryコンポーネントであるLoggregatorは、アプリケーションと、更新および実行時にアプリケーションとやり取りするCloud Foundryシステムコンポーネントからのログ出力ストリームを提供します。

デフォルトでは、Loggregatorはログを端末に転送します。 Loggregatorがバッファできるログ情報の量を制限したくない場合は、ログをサードパーティのログ管理サービスに流すことができます。サードパーティのログ管理サービスを参照してください。

クラウドファウンドリは、ベストエフォート方式でログを収集して保存します。クライアントが十分に速くログラインを消費できない場合、Loggregatorバッファは、クライアントがそれらを消費する前にいくつかの行を上書きする必要があるかもしれません。 syslogドレインまたはCLIテールは、通常、アプリログの流れに追いつくことができます。

注意事項: この記事は、Cloud Foundry Documentaion Application Logging in Cloud Foundry (last updated: August 9, 2017) からの独自の翻訳とコメントです。内容を保証するものではありません。

コメント: Bluemixでは、Cloud Foundryロギングに加えて、IBMコンテナのロギング、Bluemixコンソールログ分析、Kibana ログ分析などの拡張機能があり、Bluemixマニュアル「モニターとロギング」で内容を確認できます。

ログ行の内容

すべてのログ行には4つのフィールドがあります。

Timestamp
Log type (origin code)
Channel: either STDOUT or STDERR
Message

Loggregatorは、ログデータを受信したときにタイムスタンプを割り当てます。ログデータはLoggregatorには不透明で、単にログラインのメッセージフィールドに格納されます。ログデータをLoggregatorに送信するアプリケーションまたはシステムコンポーネントは、独自のタイムスタンプを含むことがあり、メッセージフィールドに表示されます。

Origin code は、異なるログタイプを区別します。システム構成要素からのOrigin codeは 3文字である。アプリ起源コードは、APPの後にスラッシュとアプリインスタンスを示す数字が続きます。

多くのフレームワークは、STDOUTとSTDERRとは別のアプリケーションログに書き込みます。これはLoggregatorではサポートされていません。ログがLoggregatorストリームに含まれるようにするには、アプリケーションがSTDOUTまたはSTDERRに書き込む必要があります。あなたのアプリが自動的にSTDOUTとSTDERRだけにログを書き込むことを自動的に保証するかどうかを判断するためにあなたのアプリが使うビルドパックをチェックしてください。いくつかのビルドパックはこれを行い、いくつかはそうしません。

ログの種類とそのメッセージ

以下の例に示すように、ログの種類によってメッセージ・フォーマットが異なります。コードに付加される数字は、インスタンス・インデックスを示します. 0は最初のインスタンス、1は2番目のインスタンスなどです。

API

ユーザーはアプリケーション状態を変更するAPI呼び出しを行います。 APIを担当するCloud FoundryコンポーネントであるCloud Controllerは、それが応答するアクションを記録します。

例：

2016-06-14T14:10:05.36-0700 [API/0]      OUT Updated app with guid cdabc600-0b73-48e1-b7d2-26af2c63f933 ({"name"=>"spring-music", "instances"=>1, "memory"=>512, "environment_json"=>"PRIVATE DATA HIDDEN"})

STG

Diegoセルまたは Droplet Execution Agentは、アプリケーションのステージングまたは再構築時にSTGログを出力します。これらのアクションは、ユーザーが要求した希望の状態を実装します。ドロップレットがアップロードされた後、STGメッセージが終了し、CELLメッセージが開始されます。 STGの場合、インスタンスインデックスはほぼ常に0です。

例：

2016-06-14T14:10:27.91-0700 [STG/0]      OUT Staging...

RTR

ルーターは、HTTP要求をアプリケーションにルーティングするときにRTRログを出力します。ルータメッセージには、アプリ名の後ろにルータタイムスタンプが続き、次にHTTPリクエストからの選択が含まれます。

例：

2016-06-14T10:51:32.51-0700 [RTR/1]      OUT www.example.com - [14/06/2016:17:51:32.459 +0000] "GET /user/ HTTP/1.1" 200 0 103455 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/36.0.1985.123 Safari/537.30" 192.0.2.132:46359 x_forwarded_for:"198.51.100.120" x_forwarded_proto:"http" vcap_request_id:9365d216-623a-45cb-6ef6-eba495c19fa8 response_time:0.059468637 app_id:79cc58aa-3737-43ae-ac71-39a2843b5178

Zipkinトレースログ

Cloud FoundryでZipkinトレースログが有効になっている場合、GorouterアクセスログメッセージにはZipkin HTTPヘッダーが含まれます。

次に、Zipkinヘッダーを含むアクセスログメッセージの例を示します。

2016-11-23T16:04:01.49-0800 [RTR/0]      OUT www.example.com - [24/11/2016:00:04:01.227 +0000] "GET / HTTP/1.1" 200 0 109 "-" "curl/7.43.0" 10.0.2.150:4070 10.0.48.66:60815 x_forwarded_for:"198.51.100.120" x_forwarded_proto:"http" vcap_request_id:87f9d899-c7a4-46cd-7b76-4ec35ce9921b response_time:0.263000966 app_id:8e5d6451-b369-4423-bce8-3a7a9e479dbb app_index:0 x_b3_traceid:"2d5610bf5e0f7241" x_b3_spanid:"2d5610bf5e0f7241" x_b3_parentspanid:"-"

Zipkinトレースの詳細については、「HTTPヘッダーのZipkinトラッキング」を参照してください。

LGR

LoggregatorはLGRを発行し、ロギングプロセスの問題を示します。例としては、“can’t reach syslog drain url” and “dropped log messages due to high rate.”

APP

すべてのアプリは、開発者の選択に応じてログを出力します。
例：

2016-06-14T14:10:15.18-0700 [APP/0]      OUT Exit status 0

SSH

Diegoセルは、ユーザーがcf sshコマンドを使用してSSH経由でアプリケーションコンテナにアクセスすると、SSHログを出力します。
例：

2016-06-14T14:16:11.49-0700 [SSH/0]      OUT Successful remote access by 192.0.2.33:7856

CELL
Diegoセルは、アプリの起動時または停止時にCELLログを出力します。これらのアクションは、ユーザーが要求した希望の状態を実装します。 Diegoセルは、アプリケーションがクラッシュしたときにもメッセージを出力します。
例：

2016-06-14T13:44:38.14-0700 [CELL/0]     OUT Successfully created container

あなたのアプリからのログへの書き込み

あなたのアプリはSTDERRまたはSTDOUTにログを書き込む必要があります。通常は両方ともバッファリングされているため、メッセージをLoggregatorに送信する前にバッファをフラッシュしてください。

また、ログメッセージをSTDERRまたはSTDOUTに同期して書き込むこともできます。このアプローチは、アプリのパフォーマンスに影響する可能性があるため、主にデバッグに使用されます。

コマンドライン・インターフェイスでのログの表示

cf logsコマンドを使用して、CLIでログを表示します。テール、ダンプ、またはログ出力をフィルタリングすることができます。

テーリングログ

cf logs APP_NAMEは、Loggregatorの出力を端末にストリームします。

例：

$ cf logs spring-music
Connected, tailing logs for app spring-music in org example / space development as admin@example.com...

2016-06-14T15:16:12.70-0700 [RTR/4]      OUT www.example.com - [14/06/2016:22:16:12.582 +0000] "GET / HTTP/1.1" 200 0 103455 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.102 Safari/537.36" 192.0.2.206:27743 x_forwarded_for:"203.0.113.222" x_forwarded_proto:"http" vcap_request_id:bd3e6ed1-5dd0-43ab-70ed-5d232b577b09 response_time:0.12050583 app_id:79bb58ab-3737-43be-ac70-39a2843b5177
2016-06-14T15:16:20.06-0700 [RTR/4]      OUT www.example.com - [14/06/2016:22:16:20.034 +0000] "GET /test/ HTTP/1.1" 200 0 6879 "http://www.example.com/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.102 Safari/537.36" 192.0.2.206:2228 x_forwarded_for:"203.0.113.222" x_forwarded_proto:"http" vcap_request_id:a31f0b1d-3827-4b8f-57e3-6f42d189f025 response_time:0.033311281 app_id:79bb58aa-3747-43be-ac70-39a3843b5178
2016-06-14T15:16:22.44-0700 [RTR/4]      OUT www.example.com - [14/06/2016:22:17:22.415 +0000] "GET /test5/ HTTP/1.1" 200 0 5461 "http://www.example.com/test5" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.102 Safari/537.36" 192.0.2.206:2228 x_forwarded_for:"203.0.113.322" x_forwarded_proto:"http" vcap_request_id:5d6855a2-4a79-4432-7927-de8215f5a2c7 response_time:0.029211609 app_id:79bb58aa-3737-43bb-ac70-39a2943b5178
    ...

Ctrl + C（^ C）を使用して、リアルタイムストリームを終了します。

ログのダンプ

cf logs APP_NAME --recentは、Loggregatorバッファ内のすべての行を表示します。

ログのフィルタリング

ログ出力のサブセットを表示するには、選択したフィルタリングコマンドと一緒にcfログを使用します。次の例では、grep -vはすべてのルータログを除外します。

$ cf logs spring-music --recent | grep -v RTR
2016-06-14T14:10:05.36-0700 [API/0]      OUT Updated app with guid cdabc604-0b73-47e1-a7d5-24af2c63f723 ({"name"=>"spring-music", "instances"=>1, "memory"=>512, "environment_json"=>"PRIVATE DATA HIDDEN"})
2016-06-14T14:10:14.52-0700 [APP/0]      OUT - Gracefully stopping, waiting for requests to finish
2016-06-14T14:10:14.52-0700 [CELL/0]     OUT Exit status 0
2016-06-14T14:10:14.54-0700 [APP/0]      OUT === puma shutdown: 2016-06-14 21:10:14 +0000 ===
2016-06-14T14:10:14.54-0700 [APP/0]      OUT - Goodbye!
2016-06-14T14:10:14.56-0700 [CELL/0]     OUT Creating container
    ...