真實世界：使用WCF擴展記錄服務調用時間

WCF 可擴展性

WCF 提供了許多擴展點供開發人員自定義運行時行為。 WCF 在 Channel Layer 之上還提供了一個高級運行時，主要是針對應用程序開發人員。在 WCF 文檔中，它常被稱為服務模型層（Service Model Layer）。該高級運行時主要由一個稱作 Dispatcher（在 ServiceHost 的 Context 中）的組件和一個稱作 Proxy（在客戶端的 Context 中）的組件組成。

（圖片引自 MSDN Magazine : Extending WCF with Custom Behaviors）

每個擴展點都使用接口定義來擴展。

Stage	Interceptor Interface	Description
Parameter Inspection	IParameterInspector	Called before and after invocation to inspect and modify parameter values.
Message Formatting	IDispatchMessageFormatter IClientFormatter	Called to perform serialization and deserialization.
Message Inspection	IDispatchMessageInspector IClientMessageInspector	Called before send or after receive to inspect and replace message contents.
Operation Selection	IDispatchOperationSelector IClientOperationSelector	Called to select the operation to invoke for the given message.
Operation Invoker	IOperationInvoker	Called to invoke the operation.

Behavior 是一種特殊類型的類，它在 ServiceHost/ChannelFactory 初始化過程中擴展運行時行為。WCF 有四種類型的行為：服務行為、終結點行為、契約行為和操作行為。

Scope	Interface	Potential Impact
		Service	Endpoint	Contract	Operation
Service	IServiceBehavior	✗	✗	✗	✗
Endpoint	IEndpointBehavior		✗	✗	✗
Contract	IContractBehavior			✗	✗
Operation	IOperationBehavior				✗

每種行為類型也是通過不同的接口定義來擴展，它們都共用一組相同的方法。一個例外是，IServiceBehavior 沒有 ApplyClientBehavior 方法，因為服務行為不能用於客戶端。

Method	Description
Validate	Called just before the runtime is built—allows you to perform custom validation on the service description.
AddBindingParameters	Called in the first step of building the runtime, before the underlying channel is constructed, allows you to add parameters to influence the underlying channel stack.
ApplyClientBehavior	Allows behavior to inject proxy (client) extensions. Note that this method is not present on IServiceBehavior.
ApplyDispatchBehavior	Allows behavior to inject dispatcher extensions.

WCF擴展點

（圖片引自 lovecindywang = lovecherry 博客）

案例：使用WCF擴展記錄服務調用時間

服務定義：

  [ServiceContract]
  public interface ICalculatorService
  {
    [OperationContract]
    int Add(int a, int b);
  }

服務實現：

  public class CalculatorService : ICalculatorService
  {
    public int Add(int a, int b)
    {
      return a + b;
    }
  }

配置文件：

  <system.serviceModel>
    <services>
      <service name="WcfExtensibilityTestServiceConsole.CalculatorService">
        <endpoint address="" binding="netTcpBinding" bindingConfiguration="" 
                  contract="WcfExtensibilityTestServiceConsole.ICalculatorService" 
                  name="myCalculatorServiceEndpoint"/>
        <endpoint address="mex" binding="mexTcpBinding" contract="IMetadataExchange"/>
        <host>
          <baseAddresses>
            <add baseAddress="net.tcp://localhost:12345/CalculatorService"/>
          </baseAddresses>
        </host>
      </service>
    </services>
    <behaviors>
      <serviceBehaviors>
        <behavior>
          <serviceMetadata/>
          <serviceDebug includeExceptionDetailInFaults="true"/>
        </behavior>
      </serviceBehaviors>
    </behaviors>
  </system.serviceModel>

問題描述

現在需要記錄每次服務調用執行所需的時間，比如可以將測量的方法執行時間傳遞給 PerformanceCounter 用於性能計數，或者直接寫入到日志中等。

方式一：直接在方法內測量

  public class CalculatorService : ICalculatorService
  {
    public int Add(int a, int b)
    {
      Stopwatch watch = Stopwatch.StartNew();

      int result = a + b;
      Thread.Sleep(TimeSpan.FromMilliseconds(123)); // waste time here

      Debug.WriteLine(string.Format("Method [{0}] execution cost [{1}] milliseconds.",
        "Add", watch.ElapsedMilliseconds));

      return result;
    }
  }

這種方法淺顯易懂，但如果服務所提供的功能過多，會導致大量冗余代碼。

方式二：形成測量類簡化代碼

  public class Measure : IDisposable
  {
    private Stopwatch _watch = null;

    protected Measure(string methodName)
    {
      MethodName = methodName;
      _watch = new Stopwatch();
    }

    public string MethodName { get; private set; }

    public void Start()
    {
      _watch.Start();
    }

    public void Stop()
    {
      _watch.Stop();

      Debug.WriteLine(string.Format("Measure method [{0}] execution cost [{1}] milliseconds.",
        MethodName, _watch.ElapsedMilliseconds));
    }

    public static Measure StartNew(string methodName)
    {
      Measure m = new Measure(methodName);
      m.Start();
      return m;
    }

    public void Dispose()
    {
      Stop();
      _watch = null;
    }
  }

  public class CalculatorService : ICalculatorService
  {
    public int Add(int a, int b)
    {
      using (var measure = Measure.StartNew("Add"))
      {
        Thread.Sleep(TimeSpan.FromMilliseconds(123)); // waste time here
        return a + b;
      }
    }
  }

此種方式簡化了代碼，但仍然需要在各自方法內實現，並需提供方法名作為參數。

使用 Message Inspection 來解決問題

我們定義類 IncomingMessageLoggerInspector 來實現 IDispatchMessageInspector 接口。

    #region IDispatchMessageInspector Members

    public object AfterReceiveRequest(
      ref Message request, 
      IClientChannel channel, 
      InstanceContext instanceContext)
    {
      var context = OperationContext.Current;
      if (context == null) return null;

      var operationName = ParseOperationName(context.IncomingMessageHeaders.Action);

      return MarkStartOfOperation(
        context.EndpointDispatcher.ContractName, operationName, 
        context.SessionId);
    }

    public void BeforeSendReply(ref Message reply, object correlationState)
    {
      var context = OperationContext.Current;
      if (context == null) return;

      var operationName = ParseOperationName(context.IncomingMessageHeaders.Action);

      MarkEndOfOperation(
        context.EndpointDispatcher.ContractName, operationName, 
        context.SessionId, correlationState);
    }

    #endregion

通過服務的當前上下文實例，我們可以獲取到服務被調用的契約名稱 ContractName，並且可以在 IncomingMessageHeaders 總解析出被調用的 OperationName。

我們在方法 MarkStartOfOperation 中啟動 Stopwatch 開始測量執行時間，在方法執行完畢后服務模型會調用 BeforeSendReply 並將 Stopwatch 實例引用傳遞至 correlationState，此時我們可以在方法 MarkEndOfOperation 中解決時間測量，並打印日志。

    #region Private Methods

    private static string ParseOperationName(string action)
    {
      if (string.IsNullOrEmpty(action)) return action;

      string actionName = action;

      int index = action.LastIndexOf('/');
      if (index >= 0)
      {
        actionName = action.Substring(index + 1);
      }

      return actionName;
    }

    private static object MarkStartOfOperation(
      string inspectorType, string operationName, string sessionId)
    {
      var message = string.Format(CultureInfo.InvariantCulture,
        "Operation [{0}] was called at [{1}] on [{2}] in thread [{3}].",
        operationName, inspectorType,
        DateTime.Now.ToString(@"yyyy-MM-dd HH:mm:ss.ffffff", CultureInfo.InvariantCulture),
        Thread.CurrentThread.ManagedThreadId);

      Debug.WriteLine(message);

      return Stopwatch.StartNew();
    }

    private static void MarkEndOfOperation(
      string inspectorType, string operationName, 
      string sessionId, object correlationState)
    {
      var watch = (Stopwatch)correlationState;
      watch.Stop();

      var message = string.Format(CultureInfo.InvariantCulture,
        "Operation [{0}] returned after [{1}] milliseconds at [{2}] on [{3}] in thread [{4}].",
        operationName, watch.ElapsedMilliseconds, inspectorType,
        DateTime.Now.ToString(@"yyyy-MM-dd HH:mm:ss.ffffff", CultureInfo.InvariantCulture),
        Thread.CurrentThread.ManagedThreadId);

      Debug.WriteLine(message);
    }

    #endregion

此時，我們需要定義 EndpointBehavior 來講 Inspector 設置到 DispatchRuntime 中。

  public class IncomingMessageLoggerEndpointBehavior : IEndpointBehavior
  {
    #region IEndpointBehavior Members

    public void AddBindingParameters(
      ServiceEndpoint endpoint, 
      BindingParameterCollection bindingParameters)
    {
    }

    public void ApplyClientBehavior(
      ServiceEndpoint endpoint, 
      ClientRuntime clientRuntime)
    {
    }

    public void ApplyDispatchBehavior(
      ServiceEndpoint endpoint, 
      EndpointDispatcher endpointDispatcher)
    {
      if (endpointDispatcher != null)
      {
        endpointDispatcher.DispatchRuntime.MessageInspectors.Add(
          new IncomingMessageLoggerInspector());
      }
    }

    public void Validate(ServiceEndpoint endpoint)
    {
    }

    #endregion
  }

然后，我們在 ServiceHost 實例化后，未Open前，將 IncomingMessageLoggerEndpointBehavior 添加至 Endpoint 的 Behaviors 中。

  class Program
  {
    static void Main(string[] args)
    {
      ServiceHost host = new ServiceHost(typeof(CalculatorService));

      foreach (var endpoint in host.Description.Endpoints)
      {
        endpoint.Behaviors.Add(new IncomingMessageLoggerEndpointBehavior());
      }

      host.Opened += new EventHandler(delegate(object obj, EventArgs e)
      {
        Debug.WriteLine(typeof(CalculatorService).Name + " 服務已經啟動！");
      });

      host.Open();

      Console.ReadKey();
    }
  }

使用 WcfTestClient.exe 調用服務，執行 2 + 3 查看結果，

在 Debug 輸出中可以看到，

使用配置文件定制

使用配置文件定制擴展的優點就是可以按需添加和刪除擴展，而無需改動代碼。比如當發現系統有性能問題時，添加該擴展來查看具體哪個方法執行速度慢。

需要定義類來實現 BehaviorExtensionElement 抽象類。

  public class IncomingMessageLoggerEndpointBehaviorExtension : BehaviorExtensionElement
  {
    public override Type BehaviorType
    {
      get { return typeof(IncomingMessageLoggerEndpointBehavior); }
    }

    protected override object CreateBehavior()
    {
      return new IncomingMessageLoggerEndpointBehavior();
    }
  }

在配置文件中添加擴展項，

    <extensions>
      <behaviorExtensions>
        <add name="incomingMessageLogger" 
             type="WcfExtensibilityTestServiceConsole.Extensions.IncomingMessageLoggerEndpointBehaviorExtension, WcfExtensibilityTestServiceConsole"/>
      </behaviorExtensions>
    </extensions>

在終結點行為中添加該擴展定義，

    <behaviors>
      <serviceBehaviors>
        <behavior>
          <serviceMetadata/>
          <serviceDebug includeExceptionDetailInFaults="true"/>
        </behavior>
      </serviceBehaviors>
      <endpointBehaviors>
        <behavior>
          <incomingMessageLogger/>
        </behavior>
      </endpointBehaviors>
    </behaviors>

使用 ServiceBehavior 擴展

同理，如果服務實現了多個 Endpoint，則想在所有 Endpoint 上添加該擴展，除了可以逐個添加或者使用 behaviorConfiguration 來配置。

另一個方法是可以借助 IServiceBehavior 的擴展實現。

  public class IncomingMessageLoggerServiceBehavior : IServiceBehavior
  {
    #region IServiceBehavior Members

    public void AddBindingParameters(
      ServiceDescription serviceDescription, 
      ServiceHostBase serviceHostBase, 
      Collection<ServiceEndpoint> endpoints, 
      BindingParameterCollection bindingParameters)
    {
    }

    public void ApplyDispatchBehavior(
      ServiceDescription serviceDescription, 
      ServiceHostBase serviceHostBase)
    {
      if (serviceHostBase != null)
      {
        foreach (ChannelDispatcher channelDispatcher in serviceHostBase.ChannelDispatchers)
        {
          foreach (EndpointDispatcher endpointDispatcher in channelDispatcher.Endpoints)
          {
            endpointDispatcher.DispatchRuntime.MessageInspectors.Add(
              new IncomingMessageLoggerInspector());
          }
        }
      }
    }

    public void Validate(
      ServiceDescription serviceDescription, 
      ServiceHostBase serviceHostBase)
    {
    }

    #endregion
  }

原理相同，僅是遍歷通道分配器中所有的終結點，逐一添加 Inspector。

同理，如果需要在配置文件中使用，也需要實現一個 BehaviorExtensionElement 類。

  public class IncomingMessageLoggerServiceBehaviorExtension : BehaviorExtensionElement
  {
    public override Type BehaviorType
    {
      get { return typeof(IncomingMessageLoggerServiceBehavior); }
    }

    protected override object CreateBehavior()
    {
      return new IncomingMessageLoggerServiceBehavior();
    }
  }

此時的配置文件描述如下：

    <behaviors>
      <serviceBehaviors>
        <behavior>
          <serviceMetadata/>
          <serviceDebug includeExceptionDetailInFaults="true"/>
          <incomingMessageLogger/>
        </behavior>
      </serviceBehaviors>
    </behaviors>
    <extensions>
      <behaviorExtensions>
        <add name="incomingMessageLogger" 
             type="WcfExtensibilityTestServiceConsole.Extensions.IncomingMessageLoggerServiceBehaviorExtension, WcfExtensibilityTestServiceConsole"/>
      </behaviorExtensions>
    </extensions>

參考資料

• Extending WCF with Custom Behaviors
• WCF Extensibility – Message Inspectors
• WCF擴展
• Introduction to Extensibility
• Carlos Figueira MSDN blog