[アーティクル]
08/28/2015

June 2010

Volume 25 Number 06

クラウドの診断 - Windows Azure でログ記録とトレースを制御する

Mike Kelly | June 2010

多くのプログラマと同様、私が初めてコードを記述し始めたときは、print ステートメントを使用してデバッグを行いました。デバッガーの使い方を知らなかったので、print ステートメントは、プログラムの実行時の動作を確認するための、おおざっぱながらも効果的な方法でした。その後、実際のデバッガーの使い方を学んだので、print ステートメントをデバッグツールとして使用することはなくなりました。

サーバーで実行されるコードを記述し始めた時期まで話を進めると、これまで利用していた print ステートメントが、"ログ記録とトレース" という、さらに洗練された方法に進化しているのがわかりました。どちらも、すべてのサーバーアプリケーションのプログラマにとって必須の技法です。

たとえデバッガーを運用サーバーのアプリケーションにアタッチできたとしても (アプリケーションをホストしているコンピューターのセキュリティ制限によって不可能な場合がほとんどです)、サーバーアプリケーションで発生する問題の種類を、従来のデバッガーを使用して明らかにすることは容易ではありません。多くのサーバーアプリケーションは分散され、複数のコンピューターで実行されているため、1 台のコンピューターで発生している問題をデバッグしても、実際の問題を十分診断しているとは限りません。

さらに、サーバーアプリケーションは、従来のデバッガーの使い方を知らない運用スタッフの管理下で実行される場合がほとんどで、問題が発生するたびに開発者を呼び出すことは望まれなかったり実用的でなかったりします。

今回の記事では、サーバーアプリケーション向けに使用する、いくつかの基本的なログ記録、トレース、およびデバッグの技法について説明します。続いて、これらの技法を Windows Azure プロジェクト向けに使用する方法について詳しく説明します。この記事を読み進めていくと、ログ記録とトレースがいくつかの実際のアプリケーションでどのように使用されているのかがわかります。また、Windows PowerShell を使用して、実行中のサービスの診断を管理する方法についても紹介します。

ログ記録の方針

すべてのサーバーアプリケーション (および、Windows Azure で実行される Web アプリケーションを含めて、基本的にはすべての Web アプリケーション) では、ログ記録とトレースの方針が最初から設計されているのが理想的です。ログ情報は、各コンポーネント内で起こっているほぼすべてのことを説明できるほどしっかりしたものにすべきです。しかし、私が初めてプログラムに追加した print ステートメントがあまりにも多くの情報を出力したのと同様に、ログ記録でも出力される情報が多すぎることがあります。したがって、適切に設計されたログ記録とトレースには、任意のコンポーネントから得られるログ記録の種類と量を調整する方法が含まれています。これにより、運用スタッフや開発者は、(おそらく特定のコンピューターで) 適切に動作していない特定のコンポーネントに集中的に取り組むことで、アプリケーションを紛らわしくしたり、ことによると低速にしたりする可能性がある多くの不要な情報をログに記録することなく、そのコンポーネント内で起こっていることを正確に判断できる多くの情報を得ることができます。

また、サーバーアプリケーションは分散アプリケーションになるのが一般的なので、(おそらくアプリケーションのさまざまな役割を担う) 複数のコンピューターから情報を収集して集計し、特定の問題が発生したときの動作の全容を把握しなければなりません。そのため、複数のコンピューターを通じてトランザクションスレッドを特定する方法が重要になり、これにより問題発生後の集計が可能になります。

Windows Azure で使用できるログ記録は、複数回にわたって行われた Community Technology Preview (CTP) リリースを通じて確立されてきました。初期のログ記録は print ステートメントとあまり変わりがなく、Windows Azure テーブルストレージにテキストとしてキャプチャされていました。Windows Azure で、Windows イベントトレーシング (ETW) フレームワークに基づき、非常に多くの機能を備え、完全に機能するログ記録とトレースのインフラストラクチャが提供されたのは PDC09 での発表が最初です。

この ETW フレームワークは、ASP.NET では、System.Diagnostics 名前空間のクラスを通じてサポートされます。Microsoft.WindowsAzure.Diagnostics 名前空間は、標準の System.Diagnostics クラスから派生して拡張されています。Windows Azure 環境では、この名前空間により System.Diagnostics がログフレームワークとして使用可能になります。図 1 に、Windows Azure Diagnostics (Windows Azure 診断) によって ETW が実装されるしくみを示します。

図 1 Windows Azure 診断の概要

ETW では、コードで 1 つまたは複数の TraceSource のログを記録する 1 つのモデルが提供されます。各ソースを通じて実行できるログ記録のレベルは、SourceSwitch によって制御されます。次に、ソースが 1 つまたは複数のコンシューマーに接続され、コンシューマーがさまざまな方法でログ情報を保存します。

Windows Azure では、生成したログ情報を Windows Azure のテーブルストレージまたはブロブストレージに保存するために、標準のコンシューマーとリスナーが用意されています。また、イベントデータで異なる処理を実行する場合は、独自のコンシューマーを作成することも、市販のコンシューマーを使用することも可能です (ただし、一部の市販コンシューマーは Windows Azure 環境で機能するよう変更しなければならない場合があります)。

ETW フレームワークは、TraceEventType と各イベントを関連付けます (図 2 参照)。重大度を表す最初の 5 行は最もよく使用される値で、これらはトレース出力の相対重要度を示しています。Suspend、Resume、および Transfer の各型は、Windows Communication Foundation (WCF) で使用されます。

図 2 トレースイベントの型

TraceEventType	値	意味
Critical	0x0001	致命的なエラーまたはアプリケーションのクラッシュ
Error	0x0002	回復可能なエラー
Warning	0x0004	重大ではない問題 (より深刻な問題が発生する兆候を示す場合がある)
Information	0x0008	情報メッセージ
Verbose	0x0010	デバッグトレース (実行フローの詳細情報、パラメーターなど)
Start	0x0100	論理操作の開始
Stop	0x0200	論理操作の停止
Suspend	0x0400	論理操作の中断
Resume	0x0800	論理操作の再開
Transfer	0x1000	新しいアクティビティへの転送

本当に深刻な問題だけを検出するのであれば、Critical 値と、おそらく Error 値をキャプチャするようにします。動作に関する多くの情報を必要とする場合は、Verbose より上のすべての値を確認します。

ログ記録の方針では、イベントの種類と、この表の階層の下方にある値を持つ大量のログエントリについては一貫した使い方をすべきです。アプリケーションでこれらの値すべてのログ記録を有効にすれば、事実上、アプリケーションの実行フローすべてをカバーすることができます。このことは、運用環境でエラーや問題のトラブルシューティングを行う場合に非常に重要になることがあります。

リスナー、ソース、およびスイッチをフックして、さまざまなレベルの出力をプログラムから有効にできますが、これは構成ファイルを通じて行うのが一般的です。app.config (Windows Azure Worker ロールの場合) または web.config (Windows Azure Web ロールの場合) を使用して、出力を構成できます。ただし、後半で詳しく説明しますが、これを ServiceConfiguration.cscfg に追加すると、実行コードに更新を再配布したり、サービスを停止したりさえすることなく、Windows Azure サービスを実行しながら、ログ記録とトレースのオプションを調整できます。また、Windows Azure では、RESTful インターフェイスも公開され、一部のログ記録オプションをリモートで制御できます。Windows PowerShell では、RESTful インターフェイスを利用できます。

ログ記録、トレース、およびデバッグ出力

ログ記録、トレース、およびデバッグ出力という用語が、同じ意味で使用されることがあります。ここでは、コード内で一般的に診断出力と呼ばれる出力を 4 種類に区別します。次の説明は、大まかに、最も詳細なものから順に記載しています。

デバッグ出力: アプリケーションのデバッグビルドのみで出力される情報で、リリースビルドではコンパイル時に除外されます (どちらのビルドかは、DEBUG プリプロセッサシンボルがコンパイル時に定義されているかどうかに応じます。Visual Studio の既定では、デバッグビルドのみ定義されます)。一般に、デバッグ出力にはアサートのような情報が含まれます。アサートを追加すると、コードが適切な前提条件に従っていない場合やバグにつながる場合を検出でき、データ構造をダンプすることもできます。このような情報を追加すると、デバッグ中およびテスト中にアルゴリズムをデバッグできます。
トレース: 制御フローと実行時のプログラム状態を追跡することを目的とするステートメントです。 デバッガーを実行して、コードを実行し、[ウォッチ] ウィンドウで主な変数の値を確認しているところを思い浮かべてください。トレースステートメントは、デバッガーをアタッチできない場合にその操作を模倣することを目的としています。アプリケーションの各制御ポイントでたどった経路を確認できる十分なコンテキストが提供され、トレースステートメントを読み取ることによってコードをある程度理解できるのが理想的です。トレースは、コンパイル時に TRACE プリプロセッサシンボルが定義されているときに有効になり、リリースビルドにもデバッグビルドにも定義できます (Visual Studio の既定では、デバッグビルドにもリリースビルドにも TRACE が定義されていますが、これは当然変更できます)。
イベントログ: アプリケーションの実行中に主なイベント (たとえば、トランザクションの開始やデータベースへのアイテムの追加など) をキャプチャすることを目的とするステートメントです。イベントログとトレースが異なるのは、詳細な制御フローではなく、主要な状態がキャプチャされる点です。
エラーログ: 例外的な状況や危険を伴う可能性のある状況をキャプチャする、イベントログの特殊なケースです。この例にはキャッチされるすべての例外が含まれます。アクセスできることを想定している別のコンピューターのリソースにアクセスできない場合や (当然、アプリケーションでは適切に処理されるでしょうが、一応示しておきます)、エラーが返されることを予期していない API からエラーが返される場合などもあります。

また、エラーログは、まだ問題が発生していないものの、もうすぐ問題が発生する兆候 (たとえば、クォータが最大値に近づいている場合や、トランザクションが成功しているものの通常より時間がかかっている場合) を運用スタッフが把握するのに役に立ちます。こういった種類のログイベントを使用することで、運用スタッフは、問題が発生する前に積極的に対処して、アプリケーションのダウンタイムを回避できます。

優秀な開発者の大半は、アプリケーションにデバッグ出力を含めて開発中に問題を診断することに慣れており、エラーログ用になんらかの解決策を開発しています。

ただし、デバッグ出力とエラーログのオプションだけでなく、トレースとイベントログに関する堅牢な方針をたてておくことも考慮する必要があります。これらは、運用環境で大きな負荷がかかったときにしか発生しない問題を診断するのに非常に役に立ちます。

また、現在デバッグ出力と見なしているものの多くをトレースに置き換え、リリースビルドとデバッグビルドの両方で使用できるようにするかどうかも慎重に検討します。運用環境で誤動作するアプリケーションは、通常、リリースビルドで実行されています。トレースステートメントを含めていても無効にしている場合は、これらを有効にして、リリースビルドからデバッグ出力のような非常に豊富な情報を得ることで、問題の診断に役立てることができます (トレースステートメントを無効にする方法については後で説明します)。

Windows Azure のトレースとログ記録

Windows Azure のログ記録は、Windows Azure SDK に含まれていてすぐに使用できます。Logger.NET、Enterprise Library、log4net、Ukadc.Diagnostics などのログフレームワークを使用することにはいくつかのメリットがあります。これらのフレームワークは、ログメッセージに構造を追加したり、既に説明したように構成を可能にするのに役立ちます。ただし、ほとんどのログフレームワークは Windows Azure で機能するよう調整されておらず、中には単なるログフレームワークの域をはるかに超えているものもあります。

ここで紹介するサンプルコードでは、上位層では簡単に Windows Azure 標準のログ記録とトレースの API のみを使用し、動的な構成を提供することにしました。いくつかヘルパークラスが構築され、このヘルパークラスの上位にログ記録とトレースの方針向けのフレームワークが構築されていることが、おそらくおわかりいただけるでしょう。そのため、他のフレームワークを Windows Azure バージョンするための参考になるでしょう。

Visual Studio を使用して、Windows Azure で新しいサービスを作成するときは、基本的なログ記録が既に有効になっています。Windows Azure のテンプレートによって生成される Worker ロールと Web ロールの定型コードでは、診断リスナーが既に構成されて有効になっています。

Windows Azure サービスでシンプルなログ記録を有効にするには、Visual Studio で、Visual C# の Windows Azure Cloud Service (Windows Azure クラウドサービス) テンプレートを使用して新しいプロジェクトを開始します。新しいプロジェクトに名前を付けます。このサンプルでは、「MSDNSampleLoggingService」という名前を付け、[OK] をクリックします。

New Cloud Service Project (新しいクラウドサービスプロジェクト) ウィザードが実行されます。このウィザードで、プロジェクトに、[Worker Role] (Worker ロール) と [Web Role] (Web ロール) をそれぞれ 1 つずつ追加します。Worker ロールの名前を「LoggingWorkerRole」に、Web ロールの名前を「LoggingWebRole」に変更し、[OK] をクリックします。Visual Studio によってプロジェクトが作成されます。

ここで、生成されたコードを確認できます。LoggingWorkerRole プロジェクトの app.config を確認すると、次のコードが表示されます。

<?xml version="1.0" encoding="utf-8" ?>

<configuration>

  <system.diagnostics>

    <trace autoflush="false" indentsize="4">

      <listeners>

        <add name="AzureDiagnostics" type="Microsoft.WindowsAzure.Diagnostics.DiagnosticMonitorTraceListener, Mi-crosoft.WindowsAzure.Diagnostics, Version=1.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" />

      </listeners>

    </trace>

  </system.diagnostics>

</configuration>

ここでは、Windows Azure 標準の診断リスナーをコードにフックしています。つまり、これを変更しない限り、Worker ロールから実行するすべてのログ記録とトレースが Windows Azure のリスナー (DiagnosticMonitorTraceListener) に送信されます。このサービス向けに作成した Web ロールの web.config にも同じようなエントリがあるのがわかります。

Worker ロールプロジェクトの WorkerRole.cs ファイルを見ると、OnStart メソッドに次のコード行があるのがわかります。

DiagnosticMonitor.Start("DiagnosticsConnectionString");

また、Run メソッドには、次のトレース呼び出しがあるのがわかります。

// This is a sample worker implementation. Replace with your logic.

Trace.WriteLine("LoggingWorkerRole entry point called", "Information");

最後に、サービスのルートにある ServiceConfiguration.cscfg ファイルを見ると、Worker ロールと Web ロールの両方に次のコード行があるのがわかります。

<Setting name="DiagnosticsConnectionString" 

         value="UseDevelopmentStorage=true" />

このコードは、ログ記録とトレースの情報の保存に使用するストレージアカウントを Windows Azure のリスナーに指示します。この場合、ログ情報は、ローカルコンピューターの開発ストレージに保存されます。これを Windows Azure のクラウドストレージのアカウントに切り替えることで、ログをクラウドストレージに保存できます。ここで紹介しているサンプルコードから、クラウドストレージへ切り替える形式の例を次に示します。

<Setting name="DiagnosticsConnectionString" 

  value="DefaultEndpointsProtocol=https;AccountName=Xxxxxx;AccountKey=Yyyyyy" />

AccountName 値と AccountKey 値は、お使いの具体的な Azure のアカウントとキーに合わせてカスタマイズする必要があります。この情報は、サービスのストレージアカウントのポータル (windows.azure.com) から取得します。AccountName はテーブルストレージとブロブストレージのエンドポイントの URL の最初の部分 (".table.core.windows.net" より前の部分) です。AccountKey は、base-64 でエンコードされる、ストレージアカウントのプライマリアクセスキーです。

診断にはそれぞれ個別のストレージアカウントが使用されるため、診断情報を他のアプリケーションデータと区別して保存することもできます。これを行うには、ポータルページで [New Service] (新しいサービス) をクリックし、[Storage Account] (ストレージアカウント) をクリックして、(たとえば、MyAppLogs などの) 名前を付けることによって、別のストレージアカウントをセットアップします。関係グループを設定して、ログ用のストレージがサービスと同じ領域に配置されるようにすることをお勧めします。

Windows Azure サービスのトレースコードについて簡単に説明したので、作成したシンプルな Web ロールプロジェクトを実行できます。Windows Azure で提供される既定のリスナーでも、デバッグビルドでは、出力が Visual Studio の出力ウィンドウに送信されます。したがって、デバッグウィンドウに OnStart メッセージが表示されるのがわかります。

Information: LoggingWorkerRole entry point called

サービスの実行後にログを確認したい場合はどうなるでしょう。既定では、Windows Azure はログをストレージに保存しません。ロールの OnStart メソッドに次の数行のコードを追加することで、ログをストレージに保存するよう指示できます。

TimeSpan tsOneMinute = TimeSpan.FromMinutes(1);

DiagnosticMonitorConfiguration dmc =

DiagnosticMonitor.GetDefaultInitialConfiguration();



// Transfer logs to storage every minute

dmc.Logs.ScheduledTransferPeriod = tsOneMinute;

// Transfer verbose, critical, etc. logs

dmc.Logs.ScheduledTransferLogLevelFilter = LogLevel.Verbose;    

// Start up the diagnostic manager with the given configuration

DiagnosticMonitor.Start("DiagnosticsConnectionString", dmc);

このコードを WorkerRole.cs に追加して再実行すると、Windows Azure はログを 1 分おきに開発ストレージに転送します。ログを要求時に転送したり (この方法については、サンプルアプリケーションの admin.aspx.cs のコードを参照してください)、Windows PowerShell コマンドを使用したりするよう選択することもできます (これについては後半で説明します)。ログをストレージに転送したら、ストレージ容量が変化します。不要になった情報を削除するタイミングは開発者が決めることになります。

ログを Windows Azure ストレージに保存したら、ストレージテーブルを参照してログを確認するツールが必要です。ここでは、Cerebrata 社の Cloud Storage Studio (cerebrata.com、英語) を使用しました。Cerebrata 社は、以前に Azure Diagnostics Manager というツールを発表しています。また、CodePlex (codeplex.com、英語) でクラウドストレージと診断を検索して、無償のツールを入手することもできます。ログは、WADLogsTable というテーブルに追加されます (図 3 参照)。

図 3 開発ストレージに保存されたログ

ストレージ内のログを見ると、いくつかの点に気付くでしょう。まず、Windows Azure では、いくつかの情報が、ログ記録された各イベントに自動的に関連付けられます。関連付けられる情報は、タイムスタンプ、ティック数 (100 ナノ秒単位の精度で細かいタイミングが提供されます)、配置、ロール、ロールのインスタンスに関する情報などです。これにより、必要に応じて、ログを特定のインスタンスに絞り込むことができます。

次に、Level と EventId も各イベントに関連付けられます。Level は図 2 の値に対応しています。Information としてログ記録される Trace イベントの Level 値は 4、Error としてログ記録される Trace イベントの Level 値は 2 です。(定型コードと同じように) Trace.WriteLine を使用して送信される一般的なイベントの Level 値は 5 (Verbose) です。

EventId は使用者が指定する値です。前述の基本的な Trace.WriteLine の呼び出しでは、EventId は指定していません。そのため、他の Trace メソッドを使用して、EventId を渡す必要があります。

トレースとログ記録を選択して有効にする

一般的なアプリケーションは、複数の論理コンポーネントから構成されています。たとえば、Windows Azure ストレージには、データモデルを操作するデータベースコンポーネントがあります。Web ロールは管理コンポーネントとユーザーコンポーネントに分けられることがあります (アプリケーションの要件に基づいて、さらに複数の論理コンポーネントに分けられることもあります)。

ログ記録とトレースのオプション (有効にするログ記録の種類と、詳細レベルの程度) を、このようなコンポーネントに関連付けることができます。これにより、必要なコンポーネントでのみトレースを有効にすることを選択して、不要な情報の多くを取得しないようにすることができます。

ここで使用する主な手法では、Trace を直接呼び出すのではなく、複数の TraceSource インスタンスを、通常は名前空間ごとに 1 つ使用します。TraceSource には、SourceSwitch が関連付けられています。これは、ソースが有効かどうかと、希望する出力レベルを制御します。重要なことですが、SourceSwitch の値はコンパイル時ではなく、実行時に設定されます。そのため、アプリケーションを再コンパイルしたり、異なるバージョンを再配置したりすることなく、アプリケーションのさまざまな部分からの診断出力を有効または無効にできます。

WorkerDiagnostics.cs と WebDiagnostics.cs には、サンプルコードにおけるトレースソースとトレーススイッチの構成が含まれています。抜粋を次に示します。

// Trace sources

public TraceSource ConfigTrace;

public TraceSource WorkerTrace;

// Add additional sources here



// Corresponding trace switches to control 

// level of output for each source

public SourceSwitch ConfigTraceSwitch { get; set; }

public SourceSwitch WorkerTraceSwitch { get; set; }

// Add additional switches 1:1 with trace sources here

次に、ロールの構成ファイルで、これらをリスナーにフックします (図 4 参照)。このコードでは、まず、Windows Azure 標準の診断リスナーを共有リスナーに設定して、<sources> アイテムで参照できるようにします。次に、WorkerTrace ソースと ConfigTrace ソースの、2 つのソースを構成します。また、対応するスイッチを設定して、出力レベルを調整できるようにします。ConfigTrace では、最も詳細な出力が行われます。WorkerTrace では、Error のみが出力されます。

図 4 トレースソースとトレースリスナーの構成

<configuration>

  <system.diagnostics>

    <sharedListeners>

      <add type="Microsoft.WindowsAzure.Diagnostics.DiagnosticMonitorTraceListener, Microsoft.WindowsAzure.Diagnostics, Version=1.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"

        name="AzureDiagnostics">

        <filter type="" />

      </add>

    </sharedListeners>

    <sources>

      <source name="ConfigTrace">

        <listeners>

          <add name="AzureDiagnostics" />

        </listeners>

      </source>

      <source name="WorkerTrace">

        <listeners>

          <add name="AzureDiagnostics" />

        </listeners>

      </source>

    </sources>

    <switches>

      <add name="ConfigTrace" value="Verbose"/>

      <add name="WorkerTrace" value="Error"/>

    </switches>

    <trace>

      <listeners>

        <add name="AzureDiagnostics" />

      </listeners>

    </trace>

  </system.diagnostics>

</configuration>

スイッチにソースと同じ名前を付ける必要はありませんが、同じ名前を付けると作業がより簡単になります。同じ名前でない場合は、ソース要素に Trace Sources 属性を追加して、このソースの出力を制御するスイッチの名前を指定します。これにより、複数のトレースソースが 1 つのスイッチを共有できます。トレースソースとトレーススイッチの名前は、大文字と小文字が区別されるため、コード内のコンストラクターに渡す名前は、大文字と小文字が完全に一致している必要があります。

switchValue 属性を source 要素に追加して、このソースに必要なスイッチの値を指定することにより、必要に応じてスイッチを一括指定するのを避けることができます。使用するスイッチの値は、実際には、図 5 で定義されている SourceLevel の 1 つとして、構成ファイルから解析されます。この図では、TraceSource 呼び出しに渡す TraceEventType が、source の SourceLevel のセットとやりとりして、渡す対象を決定するしくみも示しています。

図 5 トレース SourceLevel と TraceEventType

トレース SourceLevel と TraceEventType

SourceLevel が単なるビットマスクで、実行時に TraceEventType と AND 演算を行い、イベントをログ記録するかどうかを判断していることにお気付きかもしれません。Warning と Activity Tracing のような組み合わせを使用するには、ここで示しているシンボル値を使用するのではなく、ビットフィールドの数値をスイッチの値として指定します。

スイッチ以外にも、リスナーには TraceFilter を含めることができます。これは、特定のメッセージの出力を許可するかどうかに関して、より高度な実行時ロジックを追加します。カスタムの TraceFilter の記述について説明すると、ここで扱う範囲を超えてしまうため触れませんが、CodePlex の Ukadc.Diagnostics プロジェクトのドキュメント (ukadcdiagnostics.codeplex.com/wikipage?title=LoggingPrimer、英語) で参考になる例を確認できます。

ログ記録の対象を実行時に変更

これは、ASP.NET トレースの既定の動作で、Windows Azure に配置されるサービスでも適切に連携します。問題は、実行時にスイッチの値を変更できるようにすることですが、Windows Azure では、サービスを再配置しないで web.config や app.config を置き換えることはできません。また、この問題に対する ASP.NET での汎用的な解決策は、WebConfiguationManager を使用して構成値を変更することでしたが、現時点の Windows Azure では、クラウドに配置済みのサービスに対してこの処理を実行することもできません。

解決策は、これらのスイッチの値を ServiceConfiguration.cscfg にコピーすることです。Windows Azure では、サービスの実行中に、開発ポータル経由でこのファイルを編集 (または新しいファイルをアップロード) できます。ただし、これを行うには、いくつか追加でコードを記述する必要があります。

既定の System.Diagnostics コードは、app.config または web.config 内の設定のみを認識しますが、ロールは、RoleEnvironmentChanging イベントと RoleEnvironmentChanged イベントを通じて、ServiceConfiguration.cscfg 内の変更に関する実行時の通知を取得します。その後、ロールをリサイクル (再起動) するか、単に構成値を更新するかを決定できます。トレーススイッチで必要なのは後者です。ロールを再起動すると、一時的に問題が隠れてしまいます。ここで紹介するサンプルコードでは、いくつかの値を ServiceConfiguration.cscfg に追加し (スキーマを提供する ServiceDefinition.csdef も編集する必要があります)、ロールにいくつかコードを追加することによって、これを行う方法を示しています。

開発ファブリックのテスト

開発ファブリックでのテストについてはどうでしょう。開発ファブリックには、クラウドに配置済みのサービスの構成を編集するための Windows Azure ポータルがありません。まず、Windows Azure が実行中の開発ファブリックサービスに割り当てた配置 ID を特定します。これは、サービスの実行中にシステムトレイから開発ファブリック UI を表示することで確認できます。この ID は、"177" のような数値になります。

ビルド時にサービスのバイナリが格納されるディレクトリに移動します。通常は、開発したサービスコードの \bin\debug や \bin\release です。ここにアプリケーションをビルドしたときに作成された ServiceConfiguration.cscfg のコピーがあります。
次に、テキストエディターを使用して、目的のトレーススイッチを使用するよう、このファイルを編集します。たとえば、サンプルコードでは、WebTrace の値を Off から Verbose に変更します。
続いて、Windows Azure SDK コマンドプロンプトで、次のコマンドを実行します。コマンドプロンプトを起動するには、[スタート] メニューをクリックし、[すべてのプログラム]、[Windows Azure SDK v1.1] の順にポイントして、[Windows Azure SDK Command Prompt] (Windows Azure SDK コマンドプロンプト) をクリックします。

csrun /update:NNN;ServiceConfiguration.cscfg

NNN は、先ほど確認した Windows Azure の配置 ID です。これにより、開発ファブリックでは、Windows Azure 開発ポータルで [Configure] (構成) をクリックしたときに、クラウドに配置済みのサービスで実行される処理 (構成設定を更新してイベントをトリガーする処理) が実行されます。

その他の診断情報

ここでは、アプリケーションから System.Diagnostics を使用してログに記録する表形式のデータを中心に取り上げましたが、Windows Azure では、特に、IIS ログや失敗した要求トレース (旧称: FREB (Failed Request Buffering: 失敗した要求バッファー)) もキャプチャできます。これらは、Windows Azure ブロブストレージに配置されるものもあれば、Windows Azure テーブルストレージに配置されるものもあります。図 6 に、使用可能なログと、それらのログの格納場所を一覧します。既定で有効にならないログは、通常、これらのログを収集するように、Windows Azure の web.config または app.config を変更する必要があります。既定で収集されないログの例を 1 つ詳しく調べて、このしくみについて説明しましょう。

図 6 Azure の標準ログオプション

ログの種類	Windows Azure のストレージ形式	既定で収集される型	説明
コードから生成される Windows Azure のログ	テーブル	4	サンプルコードに示すように、トレースリスナーを web.config ファイルまたは app.config ファイルに追加する必要があります。WADLogsTable に格納されます。
IIS 7.0 のログ	ブロブ	4	Web ロールのみです。ログは、wad-iis-logfiles\<配置 ID>\<Web ロール名>\<ロールのインスタンス>\W3SVC1 のパスの下にある、ブロブコンテナーに格納されます。
Windows 診断インフラストラクチャのログ	テーブル	4	診断サービスそのものに関する情報です。WADDiagnosticInfrastructureLogsTable に格納されます。
失敗した要求のログ	ブロブ		Web ロールのみです。web.config にある system.WebServer の設定で、トレースのオプションを設定して有効にします。ログは、wad-iis-failedreqlogfiles\<配置 ID>\<Web ロール名>\<ロールのインスタンス>\W3SVC1 のパスの下にある、ブロブコンテナーに格納されます。
Windows イベントログ	テーブル		最初に構成を設定するときに、DiagnosticMonitorConfiguration.WindowsEventLog を変更して有効にします。WADWindowsEventLogsTable に格納されます。このログの使用方法については、Steve Marx のブログ (blog.smarx.com/posts/capturing-filtered-windows-events-with-windows-azure-diagnostics、英語) を参照してください。
パフォーマンスカウンター	テーブル		DiagnosticMonitorConfiguration.PerformanceCounters を変更して有効にします。WADPerformanceCountersTable に格納されます。サンプルコードの Worker ロールは、パフォーマンスカウンターを設定しています。
クラッシュダンプ	ブロブ		CrashDumps.EnableCollection を呼び出して有効にします。wad-crash-dumps のパスの下にある、ブロブコンテナーに格納されます。ASP.NET ではほとんどの例外がハンドルされるため、一般的に、これは Worker ロールのみで役に立ちます。
カスタムエラーログ	ブロブ		ここで説明する範囲を超えているため触れません。このログの使用方法に関する有用な例については、Neil Mackenzie のブログ (nmackenzie.spaces.live.com/blog/cns!B863FF075995D18A!537.entry、英語) を参照してください。

例として、Web ロールで IIS から FREB のログ記録を有効にする方法を見てみましょう。実際の動作を確認するには、ここで提供している MSDNSampleLoggingService のサンプルコードをダウンロードします。LoggingWebRole の web.config を開き、<system.webServer> という名前のセクションを探します。図 7 のコード行が、既定の Windows Azure の web.config に追加されているのがわかります。これにより、15 秒以上かかる要求や、状態コードが 400 ～ 599 までの要求のエラーログ (failureDefinitions 要素) が生成されます。

図 7 LoggingWebRole の失敗した要求のログ記録

<tracing>

  <traceFailedRequests>

    <add path="*">

      <traceAreas>

        <add provider="ASP" verbosity="Verbose" />

        <add provider="ASPNET" 

             areas="Infrastructure,Module,Page,AppServices"

             verbosity="Verbose" />

        <add provider="ISAPI Extension" verbosity="Verbose" />

        <add provider="WWW Server"

             areas="Authentication,Security,Filter,StaticFile,CGI,Compression,Cache,RequestNotifications,Module" 

             verbosity="Verbose" />

      </traceAreas>

      <failureDefinitions timeTaken="00:00:15" statusCodes="400-599" />

    </add>

  </traceFailedRequests>

</tracing>

LoggingWebRole プロジェクトの about.aspx.cs を開くと、次のコード行を使用して、PageLoad メソッドで 18 秒間の任意の遅延が追加されているのがわかります。

System.Threading.Thread.Sleep(18000);

このコードにより、先ほど指定した定義を受けて、このページの読み込みが失敗した要求であると強制的に判断されます。

FREB のログを確認するには、アプリケーションをリビルドして開発ファブリックに配置してから、タスクバーの通知領域で開発ファブリックのコントローラーを探します (非アクティブとして非表示になっている場合がよくあるので、タスクバーの [隠れているインジケーターを表示します] ボタンをクリックしなければならない場合があります)。開発ファブリックのコントローラーを右クリックして、[Show Development Fabric UI] (開発ファブリック UI の表示) をクリックします。すると、アプリケーションの実行中は、そのアプリケーションに関する情報が表示されるようになります。

Web ロールを展開して、ロールのインスタンス (0) を右クリックします。[Open local store] (ローカルストアを開く) をクリックして、ログが格納されているローカルコンピューターのフォルダーを開きます (図 8 参照)。そのフォルダー内の \directory\DiagnosticStore フォルダーにログがあります。これは、サンプルコードの Web ロールが、診断情報を開発ストレージに格納するよう構成されているためです。DiagnosticsConnectionString をクラウドストレージのアカウントに置き換えると、ログはそのストレージアカウントに関連付けられているブロブストレージに保存されます。Cloud Storage Studio を使用して、ブロブストレージのコンテナーを探し、ログを確認することもできます。

図 8 ローカルの開発ファブリックのストレージに保存されたログを開く

実行中のサービスの診断の管理

コードにログ記録を密接にインストルメント化できますが、通常、サービスの運用中にすべてのログ情報をストレージに保存することはありません。詳細な情報 (Verbose や Information としてログ記録されている情報) を削除し、エラーや重要な情報のみをログに保存することもできます。

しかし、問題が発生した場合はどうなるでしょう。サービスの新しいバージョンを再配置したくないでしょうし、問題が魔法のように解決するかもしれません。おそらく皆さんは、特定が難しい問題を解決するのに、再起動がどれほど有効かをご存知でしょう。

しかしこれでは問題の解決にならないので、不適切な動作を行うコードを引き続き実行しながら、ログ記録のテーブルストレージやブロブストレージに格納される情報の量を増やすのが効果的です。アプリケーションを運用しながら、アプリケーション内の問題の原因が明らかになる可能性が高まります。

先ほど、特定の TraceSource で Windows Azure の診断に渡されるログの詳細を微調整する方法について説明しました。これは、ログ記録される情報のアップストリーム編集のようなものです。ここでは、TraceSource に渡される情報をストレージに保存する方法を決定する、Windows Azure の一般的な診断の設定について説明します。

Windows PowerShell コマンドレットでは、診断を含めて、実行中の Windows Azure サービスの多くの側面を管理できます。ローカルコンピューターからこれらのコマンドレットを実行すると、サービスを実行している Windows Azure のクラウドサーバーにインターネット経由で接続され、情報が提供されてパラメーターが調整されます。Windows PowerShell は Windows 7 にインストールされています。Windows Vista 用の Windows PowerShell は、microsoft.com/powershell からダウンロードできます。Windows Azure Service Management CmdLets を code.msdn.microsoft.com/azurecmdlets (英語) からダウンロードして、インストールの指示に従います。Windows Azure の診断に関連するコマンドを図 9 に示します。

図 9 Windows Azure の診断用コマンドレット

名前	説明
Get-ActiveTransfers	アクティブな診断転送のセットと、関連付けられている転送情報を返します。
Get-CommonConfigurationLogs	すべてのログバッファーの共通構成値を取得します。これには、構成の変更がポーリングされる間隔や、メモリ内のログに割り当てられるバッファーサイズなどがあります。
Get-DiagnosticAwareRoleInstances	診断監視が実行されている、アクティブなロールのインスタンスの ID を一覧で返します。
Get-DiagnosticAwareRoles	少なくとも 1 つの診断監視を正常に開始したロールのセットを一覧します。
Get-DiagnosticConfiguration	指定されたバッファー名 (Logs、Directories、PerformanceCounters、WindowsEventLogs、または DiagnosticInfrastructureLogs) のバッファー構成を取得します。
Set-CommonConfigurationLogs	すべてのログバッファーの共通構成値を設定します。
Set-FileBasedLog	ファイルベースのログのバッファー構成を設定します。
Set-InfrastructureLog	基になる Windows Azure の診断インフラストラクチャから生成されるログのバッファー構成を設定します。診断インフラストラクチャのログは、診断システム自体のトラブルシューティングに役立ちます。
Set-PerformanceCounter	サービスが収集するパフォーマンスカウンターデータのバッファー構成を設定します。
Set-WindowsAzureLog	サービスが生成する Windows Azure の基本的なログのバッファー構成を設定します。
Set-WindowsEventLog	サービスが生成する Windows イベントログのバッファー構成を設定します。
Start-OnDemandTransfer	指定されたデータバッファーのオンデマンド転送を開始します。このコマンドレットでは、データが Windows Azure ストレージ (テーブルストレージかブロブストレージのいずれか) に移動します。
Stop-ActiveTransfer	転送 ID を指定して、アクティブなオンデマンド転送を停止します。

たとえば、特定のロールのインスタンスで現在の転送パラメーターを見つけるには、DiagnosticsConnectionString で使用した、配置 ID (これは、サービスを配置する Windows Azure の開発ポータルから確認できます)、ストレージのアカウント名、およびキーを、サービスロールの app.config または web.config に渡します (図 10 参照)。Windows PowerShell では、不足している必須パラメーター (必要なロールのインスタンスとバッファーの名前) があれば入力を求められます。Logs は、Windows Azure の標準ログです。その結果、フィルターレベルが Verbose で、転送スケジュールが 1 分おきに設定されていることが表示されます。

図 10 Windows PowerShell を使用した実行中のサービスの診断構成

このロールの構成を変更するには、Set-DiagnosticConfiguration コマンドレットを使用します (図 11 参照)。転送間隔を 1 分から 2 分に変更し、フィルターを Verbose から Error に変更しています。これは、Error および Critical としてログ記録されたイベントのみがストレージに保存されることを意味します。

図 11 Windows PowerShell による診断構成の変更

おそらく、Windows PowerShell からリモートで実行できる処理のうち最も便利なのは、ログ情報を強制的に即時転送させることです。図 12 に、この方法を示します。

図 12 Windows PowerShell を使用した IIS ログの転送開始

まず、ログの既存のオンデマンド転送を照会します。現在の Windows Azure の診断実装には制限があり、一度に実行できるのは、特定の種類の 1 つのオンデマンド転送のみです。進行中の処理がないことを確認して、1 つの転送を要求するために、サービスの配置 ID、ロールとインスタンス、転送するログの種類、および転送するデータの間隔を渡します (ログの種類 Directories は、IIS ログなどのファイベースのログを意味します。Logs は、TraceSource を通じて送信される Windows Azure のテーブルベースのログです)。

また、通知キューの名前も渡します。ここでは、Windows Azure の診断から転送完了を知らせる通知が送信されます。実験では、通知キューを渡さないと、転送が行われていないように見えることがわかりました。次に、転送要求を特定する GUID を返します。その後、要求の状態を照会して、要求が行われている (つまり進行中である) ことを確認します。

現在のバージョンの Windows Azure Service Management CmdLets では、どの時点で要求が完了したかが示されないように思えますが、診断のストレージについてブロブストレージに照会すると、すぐにコンテナー階層 (または、データストレージに格納されている情報を転送するよう要求した場合は Windows Azure テーブルストレージ) にログがポップアップ表示されます。

まとめ

コード内で定義する TraceSource の構成パラメーターを調整しながら、Windows Azure Service Management CmdLets を使用して情報をストレージに保存することで、Windows Azure サービスから取得する診断出力を完全に制御できます。

もちろん、運用コードのトラブルシューティングを行うために最も重要なことは、開発当初に診断出力についてしっかりとした方針を立ててから、コード全体にわたってその方針を踏襲することです。TraceSource と Windows Azure で提供されるツールを使用して、アプリケーションからストレージに移動する診断出力の詳細を構成すれば、この診断出力をうまく利用して、問題が発生したときに必要な量の情報のみを取得できます。

サーバーで不規則に動作するコードがブラックボックスのように感じられ、不透明なのが最悪のケースです。ここで説明した堅牢な診断コードとツールを使用すると、そのブラックボックスのふたを開けて、中をのぞくことができます。

Mike Kelly は、ソフトウェア開発を中心とするコンサルタントで、大手企業への買収をまとめる手助けをしています。これまでマイクロソフトに 15 年間勤務し、さまざまな製品の開発における職務を果たし、Engineering Excellence チームの Emerging Practices のディレクターを務めました。Mike の連絡先は himself@mikekellyconsulting.com (英語のみ) です。

この記事のレビューに協力してくれた技術スタッフの Sumit Mehrotra、Michael Levin、Matthew Kerner (マイクロソフト)、Neil Mackenzie および Steven Nagy に心より感謝いたします。

次の方法で共有