はじめに
本記事は、Microsoft Azure Tech Advent Calendar 2020 の25 日目の投稿です。今回はあまりまとまった資料を見ない Windows Container の監視方法について記事を書いてみたいと思います。
TL;DR
- Windows Container は標準出力、標準エラーにログを出力しないので Log Monitor を仕込むことで docker logs や Log Analytics との連携が容易になる
- AKS や Service Fabric などクラスタ化されたコンテナアプリケーションでは Azure Monitor のコンテナー監視ソリューションで集約すると便利
Windows Containerとは
言わずもがな、コンテナとは、アプリケーションを実際の実行環境から抽象化して格納するための仮想化技術になります。コンテナプロセスは、稼働するオペレーティングシステムのカーネルを共有していますが、名前空間やコンピュータリソースを他のプロセスやコンテナから分離されることで独立した実行環境を実現するともに、言語ランタイムやソフトウェアライブラリなどのアプリケーション実行環境をコンテナ単位でセットアップすることで一貫したアプリケーションの実行環境が実現できます。
OSレベルでの仮想化なので仮想マシンを立ち上げたりするよりも軽量で手軽なため、ちょっとした開発やテスト環境にも便利なので、Visual Studio Code を統合できる [Remote-Containers] (https://code.visualstudio.com/docs/remote/containers) を使っているという話も近年よく聞く気がします。
元々コンテナ技術は、Linux から発展してきたので Linux カーネルでコンテナを動作させる（もしくは Hyper-V 技術をつかって Windows 上でLinuxコンテナを実行させる）ことが多いと思いますが、Windows カーネルでもコンテナ仮想化機能については提供されており、Windows Server 2016 以降で Windows Server Container の機能を利用することができます。
オンプレミスや、クラウド上の仮想マシンはもちろんのこと、Kubernetes でも 1.14 から Windows Server Container がサポートされているので、[Azure Kubernetes Service (AKS)] (https://docs.microsoft.com/ja-jp/azure/aks/intro-kubernetes) や Azure Service Fabric などの Container Orchestrator と呼ばれるシステムを使って、複数のノードにまたがる大規模な Windows Server Container アプリケーションをクラウド上で管理、展開することが可能になっています。
単一の Windows Container
Windows Container を使う場合、ログ監視の観点で Linux コンテナとの差異として認識しておくべきことがあります。
それは、Windows は通常、標準出力（STDOUT）及びエラー出力（STDERR）にログを出力しないという点です。
そのため、コンテナのSTDOUTとSTDERRの内容を表示する docker logs コマンドは、何も考慮していない Windows Container だとほとんど役に立ちません。
例えば、Windows IIS のベースイメージからシンプルにコンテナを起動してみます。80ポートにアクセスするとIISのデフォルトページが確認できるだけのアプリケーションです。
このとき docker logs では何の情報も得ることができません。
PS C:\Users\azureuser> docker run -d -p 80:80 --name iisapp mcr.microsoft.com/windows/servercore/iis:windowsservercore-ltsc2019
b1cc976338f0f2c96c2b4e7e7532bed00687f6bfd0238a4b4b9e80bdd2822776
PS C:\Users\azureuser> docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
b1cc976338f0 mcr.microsoft.com/windows/servercore/iis:windowsservercore-ltsc2019 "C:\\ServiceMonitor.e…" 7 seconds ago Up 4 seconds 0.0.0.0:80->80/tcp iisapp
PS C:\Users\azureuser> docker logs b1cc976338f0
PS C:\Users\azureuser>
しかし安心してください、LogMonitor というツールがオープンソースで開発されており、これを使うことでイベントログ、ETW プロバイダーやその他アプリケーションログなどといったソースをモニタリングし、STDOUT/STDERR にブリッジしてくれます。LogMonitorは以下のgithubのreleaseからexeをダウンロードすることが可能です。（現在1.1.0が最新になります）
これを使うことで docker logs からイベントログやiisのアクセスログなどの情報を docker logs と連携することができます。
LogMonitor
https://github.com/microsoft/windows-container-tools/tree/master/LogMonitor
上記の IIS のベースイメージにLogMonitorを組み込んでみます。
フォルダ構成は下記の通りで、dockerfile とLogMonitor本体であるLogMonitor.exeと設定ファイルLogMonitorConfig.jsonの3つだけのシンプルな構成です。
C:\USERS\AZUREUSER\LOGMONITOR
│ dockerfile
│
└───LogMonitor
LogMonitor.exe
LogMonitorConfig.json
dockerfile では exe と config ファイルをコピーし、LogMonitor の child プロセスとして Powershell を起動させるだけでOKです。
ちなみに、LogMonitor とは直接関係ありませんが、ENTRYPOINT のServiceMonitor.exe は、Windows サーバーコンテナー内で IIS を実行するために作成されているソフトウェアで、ENTRYPOINT に指定することで w3svc の状態を監視し状態にあわせて適切にコンテナの終了処理などをおこなえるようになります。
FROM mcr.microsoft.com/windows/servercore/iis:windowsservercore-ltsc2019
COPY LogMonitor/ C:/LogMonitor
WORKDIR /LogMonitor
SHELL ["C:\\LogMonitor\\LogMonitor.exe", "powershell.exe"]
ENTRYPOINT C:\\ServiceMonitor.exe w3svc
Configファイルでは、System イベントログとapplicationイベントログ、そしてc:\inetpub\logs以下の.logファイルをソースと指定しています。
{
"LogConfig": {
"sources": [
{
"type": "EventLog",
"startAtOldestRecord": true,
"eventFormatMultiLine": false,
"channels": [
{
"name": "system",
"level": "Information"
},
{
"name": "application",
"level": "Error"
}
]
},
{
"type": "File",
"directory": "c:\\inetpub\\logs",
"filter": "*.log",
"includeSubdirectories": true
}
]
}
}
この状態でコンテナを開始して80ポートにアクセスしてから docker logs でログを確認して見ると次の通りイベントログやアクセスログが参照できるようになります。
PS C:\Users\azureuser\LOGMONITOR> docker build -t y10e/iis2019-logmonitor:latest .
PS C:\Users\azureuser\LOGMONITOR> docker run -d -p 80:80 --name iisapp y10e/iis2019-logmonitor
PS C:\Users\azureuser\LOGMONITOR> docker logs 81f09f8dcf5c
<Source>EventLog</Source><Time>2020-11-03T03:12:11.000Z</Time><LogEntry><Channel>System</Channel><Level>Information</Level><EventId>6009</EventId><Message>Microsoft (R) Windows (R) 10.00. 17763 Multiprocessor Free.</Message></LogEntry>
<Source>EventLog</Source><Time>2020-11-03T03:12:11.000Z</Time><LogEntry><Channel>System</Channel><Level>Information</Level><EventId>6005</EventId><Message>The Event log service was started.</Message></LogEntry>
<Source>EventLog</Source><Time>2020-11-03T03:11:51.000Z</Time><LogEntry><Channel>System</Channel><Level>Information</Level><EventId>12</EventId><Message>The operating system started at system time ?2020?-?11?-?03T03:11:51.500000000Z.</Message></LogEntry>
<Source>EventLog</Source><Time>2020-11-03T03:11:51.000Z</Time><LogEntry><Channel>System</Channel><Level>Information</Level><EventId>153</EventId><Message>Virtualization-based security (policies: 0) is disabled.</Message></LogEntry>
~
<Source>EventLog</Source><Time>2020-12-21T09:37:56.000Z</Time><LogEntry><Channel>System</Channel><Level>Information</Level><EventId>7036</EventId><Message>The Distributed Transaction Coordinator service entered the running state.</Message></LogEntry>
#Software: Microsoft Internet Information Services 10.0
#Version: 1.0
#Date: 2020-12-21 09:37:03
#Fields: date time s-ip cs-method cs-uri-stem cs-uri-query s-port cs-username c-ip cs(User-Agent) cs(Referer) sc-status sc-substatus sc-win32-status time-taken
2020-12-21 09:37:03 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 172
2020-12-21 09:37:24 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 0
2020-12-21 09:37:25 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 1
2020-12-21 09:37:25 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 0
2020-12-21 09:37:27 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 0
2020-12-21 09:37:27 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 0
2020-12-21 09:37:28 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 0
2020-12-21 09:37:28 172.27.63.156 GET / - 80 - 172.16.0.4 Mozilla/5.0+(Windows+NT;+Windows+NT+10.0;+en-US)+WindowsPowerShell/5.1.17763.1490 - 200 0 0 0
Azure Monitor のコンテナー監視ソリューション
単一のコンテナではdocker logsでイベントログやアクセスログが見えるようになりましたが、Kubernetes や Service Fabricなどの複数ノードで無数にコンテナが稼働するシステムでは、いちいちノードにリモートで接続して確認するわけにもいかないのでもう少し仕組みが欲しいところです。
そんな時、Azure Monitor のコンテナー監視ソリューションが便利です。AKS や ServiceFabric の各ノード（コンテナホスト）にエージェントをインストールしておくと、Log Analytics ワークスペースに転送してログを集約してくれます。kusto クエリも使えるので複雑な検索も可能です。
Azure Monitor のコンテナー監視ソリューション
https://docs.microsoft.com/ja-jp/azure/azure-monitor/insights/containers
今回は、Service Fabric を使って動作を見ていきます。
前提条件として、Service Fabric クラスタ（VMSS）に Log Analyticsエージェントがインストールされていてworkspcaeと接続されている必要があります。もし、Log Analyticsエージェントがインストールされていない場合は、Azure CLI を使ってクラスタのVMSSに対して次のコマンドでインストールすることができます。
az vmss extension set --name MicrosoftMonitoringAgent --publisher Microsoft.EnterpriseCloud.Monitoring --resource-group <resourceGroup> --vmss-name <vmssName> --settings "{'workspaceId': '<your workspace ID here>'}" --protected-settings "{'workspaceKey': '<your workspace key here'}"
次に "コンテナ監視ソリューション" を MarketPlaceからデプロイします。このときLog Analyticsエージェントのインストール時に指定したLogAnalyticsワークスペースと紐づけておく必要があります。
あとは、ログが workspace に転送されるのを待つだけです。
Log Analytics の workspace では次のテーブルが存在することが確認できるかと思います。
| テーブル名 | 内容 |
|---|---|
| ContainerImageInventory | 各ノードで使用されている container image の種別や image ID、サイズなど |
| ContainerInventory | 各ノードで動作しているコンテナIDやName、使用ポートや状態など |
| ContainerLog | docker logs に相当するログ |
| ContainerServiceLog | 開始、停止、削除、プルのコマンドなど、Docker デーモンに関するログ |
ContainerInventory では、コンテナが稼働するホストマシンのホスト名、ContainerID、Name、使用ポート、状態などが確認できます。実際に直近1時間でクエリをかけてみると以下のようになります。
ContainerLog では、コンテナが稼働するホストマシンのホスト名と、docker logs コマンドで確認できるようにしたイベントログや IIS のアクセスログが確認できます。同じく直近1時間で、GETメソッドで "/" にアクセスしにきたアクセスログをクエリすると次のようになります。どのノードのコンテナに着弾したかわかりやすいですね。
おわりに
昨年のカレンダーを書いてた時には COVID-19 でまさか10か月近くリモートワークが続くとは夢にも思っていませんでしたが、直前かつリモートでの呼びかけにも関わらず Microsoft Azure Tech Advent Calendar 2020 が成立したことを嬉しく思います。
皆様の Azure & Technology 愛に多謝！