デバッガに出力するには

単純に、System.Diagnostics.Debugger.Log() を呼び出すだけでよい。
しかし、通常はこんなメソッドを呼び出したりはせず、System.Diagnostics.Debug クラスと System.Diagnostics.Trace クラスを使用する。
これらのクラスには Write() や WriteLine()、階層化をサポートするための Indent() や条件付き書き出すの WriteLineIf() などといったメソッドがあり、Debug クラスの各メソッドは Conditional("DEBUG")、Trace クラスの各メソッドは Conditional("TRACE") の属性が付与されているため、簡単に出力を停止することもできる。

Debug クラス, Trace クラス

この Debug と Trace の２つのクラスは、ともに TraceListener の派生クラスを保持しており、実際の出力制御はそれらのクラスによって行われる。
アプリケーション起動時*1、これらのクラスは System.Diagnostics.DefaultTraceListener のインスタンスを１つだけ保持している。
この DefaultTraceListener クラスが Debugger.Log() の呼び出しを行っているわけだ。
また、Win32 の標準デバッグ出力に対しても出力を行っているので、クラシックなデバッグ支援ツールなどとの連携も可能になっている。
これらのクラスはログ出力だけではなく Assert() メソッドのほうが使用頻度が高いだろう。

*1:アプリケーションドメイン作成時

DefaultTraceListener クラスとアプリケーション設定ファイル

DefaultTraceListener にはいくつかのプロパティがあり、出力のカスタマイズが可能になっているが、プロジェクトのルートに app.config という名前で XML ファイルを作成し、*1

<Configuration>
  <System.Diagnostics>
    <LogFilename>log.txt</LogFilename>
  </System.Diagnostics>
</Configuration>

のような記述を加えることでもう少しカスタマイズの幅を広げることができるようになっている。*2
上記の例では、LogFilename プロパティを設定していて、このプロパティにファイル名を指定していると DefaultTraceListener は指定されたファイルへ出力を追記するようになっている。

AssertUIEnabled(bool)

同名のプロパティと同じ

AutoFlush(true)

true に設定すると Write() や WriteLine() のたびに Flush() を呼び出す。

IndentSize(int)

インデントに使用するスペースの数。デフォルトは 4

LogFilename(string)

指定されたファイルへ出力を追記する。

Switches

BooleanSwitch と TraceSwitch の設定

他にも、System.Diagnostics 名前空間用に DefaultTraceListener とは関係ない設定も存在する。

*1:SDK 環境では、実行ファイルの名前が foo.exe であれば、foo.exe.config というファイル名で実行ファイルと同じ場所に作成する必要がある

*2:これは実行環境すべてで有効化される記述となるが、開発環境でのみ有効な記述方法なんてのもある

Switch クラス（BooleanSwitch クラス, TraceSwitch クラス）

前述した Switches を使用するクラスが、Switch クラスとその派生クラスである。
使用方法はドキュメントを読めばすぐにわかると思うが、これらのクラスは Switches から指定した要素の値を取り出すだけのクラスである。
System.Diagnostics/Switches 要素の中身に簡単にアクセスする手段として活用できるが、中傷クラスである Switch クラスの段階で整数値のみのサポートとなっているため、派生クラスを作成しても使いにくいことこの上ないように思える。
Switch クラスが value を文字列のまま保持しており、BooleanSwitch と TraceSwitch によってそれぞれの型に変換されている造りならよかったのだが…。

<Configuration>
  <System.Diagnostics>
    <Switches>
      <add name="switch1" value="1" />
      <add name="switch2" value="5" />
    </Switches>
  </System.Diagnostics>
</Configuration>

カスタム TraceListner の作成

Debug クラスおよび Trace クラスの出力先となる TraceListener クラスは、このクラスを派生して Write(string) と WriteLine(string) を実装するだけですぐに使えるようになるだけの実装を持っている。
Write(string) メソッドと WriteLine(string) の違いは名前の通り改行コードの付与だけの差である。

  public override void WriteLine(string message)
  {
    StringBuilder sb = new StringBuilder(message.Length + 2);
    sb.Append(message).Append(Environment.NewLine);

    this.Write(sb.ToString());
  }

よって、このような実装だけでもとりあえず問題ない実装ができるのだが、もうすこし機能を追加する必要があり、

  public override void WriteLine(string message)
  {
    StringBuilder sb = new StringBuilder(message.Length + 2);
    sb.Append(message).Append(Environment.NewLine);

    this.Write(sb.ToString());
    this.NeedIndent = true;
  }

とするのが、より理想的な実装となる。これに対して Write(string) の実装は、出力機能を別メソッドとすると、

  protected abstract WriteCore(string message);

  public override void Write(string message)
  {
    if (this.NeedIndent) this.WriteIndent();

    this.WriteCore(message);
  }

というような内容となる。

先頭行に時刻出力をもつ TraceLister の完全なコード

前述のように、TraceListener の実装をすべて行ってもよいのだが、もっと簡単に DefaultTraceListener を継承してほんの数行で作成することができる。
現在時刻の取得は DateTime.Now を利用し、パフォーマンス面の品質管理の一時チェックに利用できる程度の簡易な実行時間計測機能を PerformanceCounter を利用して追加したクラスの全コードは次のようになった。

#region *** (C) El (K.Takaoka) ! el@moonlight.gr.jp

using System;
using System.Diagnostics;
using System.Text;
using System.Runtime.InteropServices;

#endregion

namespace Lady.BUG
{
  public class LogListener : DefaultTraceListener
  {
    #region メンバ変数

    private const           string DEFAULT_FORMAT = "{0,8:f3}";
    private static readonly double msec_pc;

    // このインスタンス固有の設定値
    private bool    logDate     = true;
    private bool    logCount    = false;
    private string  format      = DEFAULT_FORMAT;
    private long    prev_pc;

    #endregion

    static LogListener()
    {
      // １秒で増えるカウント数を取得する
      long secs_pc;
      if (!QueryPerformanceFrequency(out secs_pc)) secs_pc = 0;

      // １ミリ秒のカウント数を計算する
      msec_pc = secs_pc / 1000d;
    }

    public LogListener()
    {
      // 現在のカウンタで前回値を初期化しておく
      QueryPerformanceCounter(out this.prev_pc);
    }

    #region プロパティ

    /// <summary>
    /// ログに日付を追加するかどうか
    /// </summary>
    public bool LogDate
    {
      get
      {
        return this.logDate;
      }

      set
      {
        this.logDate = value;
      }
    }

    /// <summary>
    /// ログにパフォーマンスカウンタの差を追加するかどうか
    /// </summary>
    public bool LogCounter
    {
      get
      {
        return this.logCount && (msec_pc > 0);
      }

      set
      {
        this.logCount = value;
      }
    }

    /// <summary>
    /// ログに表示するカウンタの形式文字列
    /// </summary>
    public string CounterFormat
    {
      get
      {
        return this.format;
      }

      set
      {
        if ((value == null) || (value.Length < "{0}".Length))
          this.format = DEFAULT_FORMAT;
        else
          this.format = value;
      }
    }

    #endregion

    #region TraceListener メンバ

    protected override void WriteIndent()
    {
      this.NeedIndent = false;

      StringBuilder sb = new StringBuilder(32);

      if (this.LogDate)
      {
        // 現在時刻をログに記録する
        sb.Append("[");
        sb.Append(DateTime.Now.ToString("HH:mm:ss"));
        sb.Append("] ");
      }

      if (this.LogCounter)
      {
        // 現在カウンタと前回カウンタの差をミリ秒単位でログに記録する
        long cur_pc;
        QueryPerformanceCounter(out cur_pc);

        double d = (double) (cur_pc - this.prev_pc) / msec_pc;
        this.prev_pc = cur_pc;

        sb.Append("(");
        sb.AppendFormat(this.format, d);
        sb.Append(") ");
      }
      else
      {
        // カウンタだけは更新し続ける。
        QueryPerformanceCounter(out this.prev_pc);
      }

      // インデントの前に時刻およびカウンタを出力する
      this.Write(sb.ToString());

      // インデントを出力する
      base.WriteIndent();
    }

    #endregion

    #region PInvoke defines

    [DllImport("kernel32.dll", SetLastError=true)]
    private static extern bool QueryPerformanceCounter(out long lpPerformanceCount);

    [DllImport("kernel32.dll", SetLastError=true)]
    private static extern bool QueryPerformanceFrequency(out long lpPerformanceCount);

    #endregion
  }
}

このコードは、実際に使っている実装が独自の Switch を用いて app.config ファイルを参照するようになっているため、この日記専用に調整されたものである。

  private static void Main()
  {
    // LogListener を作成
    LogListener logger = new LogListener();

    logger.LogDate     = true;
    logger.LogCounter  = true;
    logger.LogFileName = "test.log";

    // ちょっと強引に設定
    Debug.Listeners.Clear();
    Debug.Listeners.Add(logger);

    // アプリケーション実行
    context = new ApplicationContext(
        new MethodLogger(new Form1()).GetTransparentProxy() as Form1);

    Application.Run(context);
  }

こんな具合に設定して

[20:16:45] ( 287.090) Enter add_HandleDestroyed(value={System.EventHandler})
[20:16:45] (  20.253) Leave add_HandleDestroyed
[20:16:45] (   9.026) Enter set_Visible(value={True})
[20:16:45] (  46.268)     Enter Invalidate()
[20:16:45] (   8.200)     Leave Invalidate
[20:16:45] (  10.566)     Enter Invalidate()
[20:16:45] (   8.773)     Leave Invalidate
[20:16:45] (  14.486)     Enter Open()
[20:16:47] (1708.895)     Leave Open
[20:16:47] (  15.250) Leave set_Visible
[20:17:17] (29985.142) Enter Open()
[20:17:17] (   5.857)     Enter get_IsHandleCreated()
[20:17:17] (   6.302)     Leave get_IsHandleCreated {false}
[20:17:17] (   7.566)     Enter get_Handle()
[20:17:17] (   6.870)     Leave get_Handle {System.IntPtr}
[20:17:17] (   8.804)     Enter get_IsHandleCreated()
[20:17:17] (   7.495)     Leave get_IsHandleCreated {true}
[20:17:17] (   6.273)     Enter CheckFileFormat(fname={"C:\test.txt"})
[20:17:17] (   7.153)         Enter IsCxpFile(str={System.IO.FileStream})
[20:17:17] (   8.107)         Leave IsCxpFile {false}
[20:17:17] (   8.788)         Enter IsCompressCxpFile(str={System.IO.FileStream})
[20:17:17] (   7.324)         Leave IsCompressCxpFile {false}
[20:17:17] (   7.902)     Leave CheckFileFormat {FileFormat.Plain}
    ：

こんなログが取れる、と。