Home>C# Tips>

メソッド呼び出しの自動ロギング

更新日:2004/03/29

任意のクラス(ただし基底クラスはContextBoundObject)に対してメソッドの呼び出しをロギング出来るカスタム属性です。ファイル名を指定するとログをファイルに書き込みます。指定しなければ標準出力に書き出します。アスペクト指向プログラミングっぽいかな?


クラス構成

MethodCallLoggingProxy
メソッドの呼び出しに割り込んでメソッドの呼び出し、戻りのログを取ります。
MethodCallLoggingAttribute
MethodCallLoggingProxyを割り込ませるカスタム属性。
MyClass
ロギング対象となるテスト用クラス。
LoggingTest
テスト用のメインクラス。

methodlog.cs

using System;
using System.IO;
using System.Collections;
using System.Runtime.Remoting;
using System.Runtime.Remoting.Messaging;
using System.Runtime.Remoting.Proxies;
using System.Runtime.Remoting.Activation;
using System.Runtime.Remoting.Services;

// メソッドロギングプロキシ
class MethodCallLoggingProxy : RealProxy {
  readonly MarshalByRefObject target;
  readonly string logfile;

  public MethodCallLoggingProxy(MarshalByRefObject target, Type t, string logfile) 
    : base(t) {
    this.target = target;
    this.logfile = logfile;
  }

  public override IMessage Invoke(IMessage msg) {
    IMethodCallMessage call = (IMethodCallMessage)msg;
    IMethodReturnMessage res;
  IConstructionCallMessage ctor =
      call as IConstructionCallMessage;

    if (ctor != null) {
      RealProxy rp = RemotingServices.GetRealProxy(target);
      rp.InitializeServerObject(ctor);
      MarshalByRefObject tp = this.GetTransparentProxy() as MarshalByRefObject;
      res = EnterpriseServicesHelper.CreateConstructionReturnMessage(ctor, tp);
    }
    else {
      StreamWriter sw;

      // ファイル名が指定されていなければ標準出力に書き出す
      if (logfile != null) 
        sw = new StreamWriter(logfile, true);
      else
        sw = new StreamWriter(Console.OpenStandardOutput(1024));

      ArrayList input = new ArrayList();
      ArrayList output = new ArrayList();

      input.Add("\t<in>");
      for (int i = 0; i < call.InArgCount; ++i) 
        input.Add(String.Format("<{0}>{1}</{0}>", call.GetInArgName(i), call.GetInArg(i)));
      input.Add("</in>\n");

      // メソッドの実行及び、実行時間の測定
      DateTime t1 = DateTime.Now;
      res = RemotingServices.ExecuteMessage(target, call);
      DateTime t2 = DateTime.Now;

      if (res.Exception == null) {
        output.Add("\t<out>");
        for (int i = 0; i <res.OutArgCount; ++i) 
          output.Add(String.Format("<{0}>{1}</{0}>", 
            res.GetOutArgName(i), res.GetOutArg(i)));
        output.Add("</out>\n");
        output.Add(String.Format("\t<return>{0}</return>\n", res.ReturnValue));
      }
      else {
        output.Add(String.Format("\t<exception type=\"{0}\">{1}</exception>\n", 
          res.Exception.GetType(), res.Exception.Message));
      }
      sw.WriteLine("<{0} start=\"{1}\" time=\"{2}\">", call.MethodName, t1, t2 - t1);
      for (int i = 0; i < input.Count; ++i) 
        sw.Write(input[i]);
      for (int i = 0; i < output.Count; ++i)
        sw.Write(output[i]);
      sw.WriteLine(String.Format("</{0}>", call.MethodName));
      sw.Close();
    }
    return res;
  }
}

// メソッドロギング用のカスタム属性
[AttributeUsage(AttributeTargets.Class)]
public class MethodCallLoggingAttribute : ProxyAttribute {
  readonly string logfile;
  public MethodCallLoggingAttribute(string logfile) {
    this.logfile = logfile;
  }

  public override MarshalByRefObject CreateInstance(Type serverType) {
    MarshalByRefObject target = base.CreateInstance (serverType);
    RealProxy rp = new MethodCallLoggingProxy(target, serverType, logfile);
    return rp.GetTransparentProxy() as MarshalByRefObject;
  }
}

loggingtest.cs

using System;
using System.Threading;

// ロギング属性をつける
// メソッド呼び出しのログが自動生成される
[MethodCallLogging(null)]
class MyClass : ContextBoundObject {
  Random rnd = new Random((int)DateTime.Now.Ticks);

  public MyClass() {}

  public double Add(double x, double y) {
    Thread.Sleep(rnd.Next(1000));  // waitを入れる
    return x + y;
  }

  public void Multiply(double x, double y, out double z) {
    Thread.Sleep(rnd.Next(1000));  // waitを入れる
    z = x * y;
  }

  public double Divide(double x, double y) {
    Thread.Sleep(rnd.Next(1000));  // waitを入れる
    if (x < double.Epsilon) {
      throw new DivideByZeroException("Exception message");
    }
    return x / y;
  }
}

class LoggingTest {
  [STAThread]
  static void Main(string[] args) {
    MyClass my = new MyClass();
    double z;

    // inパラメータと戻り値の例
    my.Add(1.23, 4.56);
    // in,outパラメータの例
    my.Multiply(9.87, 6.54, out z);
    try {
      // 例外発生の例
      my.Divide(0, 0);
    }
    catch (Exception) {
      // do nothing
    }
  }
}

/* 実行結果
<Add start="2004/03/29 1:21:46" time="00:00:00.7031250">
        <in><x>1.23</x><y>4.56</y></in>
        <out></out>
        <return>5.79</return>
</Add>
<Multiply start="2004/03/29 1:21:46" time="00:00:00.9062500">
        <in><x>9.87</x><y>6.54</y></in>
        <out><z>64.5498</z></out>
        <return>System.Void</return>
</Multiply>
<Divide start="2004/03/29 1:21:47" time="00:00:00.1250000">
        <in><x>0</x><y>0</y></in>
        <exception type="System.DivideByZeroException">Exception message</exception>
</Divide>
*/

Home>C# Tips>