使用WCF扩展记录服务调用时间

时间:2024-01-11 08:24:50
随笔- 64  文章- 0  评论- 549 

真实世界:使用WCF扩展记录服务调用时间

WCF 可扩展性

WCF 提供了许多扩展点供开发人员自定义运行时行为。 WCF 在 Channel Layer 之上还提供了一个高级运行时,主要是针对应用程序开发人员。在 WCF 文档中,它常被称为服务模型层(Service Model Layer)。该高级运行时主要由一个称作 Dispatcher(在 ServiceHost 的 Context 中)的组件和一个称作 Proxy(在客户端的 Context 中)的组件组成。

使用WCF扩展记录服务调用时间

图片引自 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扩展点

使用WCF扩展记录服务调用时间

(图片引自 lovecindywang = lovecherry 博客)

案例:使用WCF扩展记录服务调用时间

服务定义:

1   [ServiceContract]
2 public interface ICalculatorService
3 {
4 [OperationContract]
5 int Add(int a, int b);
6 }

服务实现:

使用WCF扩展记录服务调用时间
1   public class CalculatorService : ICalculatorService
2 {
3 public int Add(int a, int b)
4 {
5 return a + b;
6 }
7 }
使用WCF扩展记录服务调用时间

配置文件:

使用WCF扩展记录服务调用时间
 1   <system.serviceModel>
2 <services>
3 <service name="WcfExtensibilityTestServiceConsole.CalculatorService">
4 <endpoint address="" binding="netTcpBinding" bindingConfiguration=""
5 contract="WcfExtensibilityTestServiceConsole.ICalculatorService"
6 name="myCalculatorServiceEndpoint"/>
7 <endpoint address="mex" binding="mexTcpBinding" contract="IMetadataExchange"/>
8 <host>
9 <baseAddresses>
10 <add baseAddress="net.tcp://localhost:12345/CalculatorService"/>
11 </baseAddresses>
12 </host>
13 </service>
14 </services>
15 <behaviors>
16 <serviceBehaviors>
17 <behavior>
18 <serviceMetadata/>
19 <serviceDebug includeExceptionDetailInFaults="true"/>
20 </behavior>
21 </serviceBehaviors>
22 </behaviors>
23 </system.serviceModel>
使用WCF扩展记录服务调用时间

问题描述

现在需要记录每次服务调用执行所需的时间,比如可以将测量的方法执行时间传递给 PerformanceCounter 用于性能计数,或者直接写入到日志中等。

方式一:直接在方法内测量

使用WCF扩展记录服务调用时间
 1   public class CalculatorService : ICalculatorService
2 {
3 public int Add(int a, int b)
4 {
5 Stopwatch watch = Stopwatch.StartNew();
6
7 int result = a + b;
8 Thread.Sleep(TimeSpan.FromMilliseconds(123)); // waste time here
9
10 Debug.WriteLine(string.Format("Method [{0}] execution cost [{1}] milliseconds.",
11 "Add", watch.ElapsedMilliseconds));
12
13 return result;
14 }
15 }
使用WCF扩展记录服务调用时间

这种方法浅显易懂,但如果服务所提供的功能过多,会导致大量冗余代码。

方式二:形成测量类简化代码

使用WCF扩展记录服务调用时间
 1   public class CalculatorService : ICalculatorService
2 {
3 public int Add(int a, int b)
4 {
5 using (var measure = Measure.StartNew("Add"))
6 {
7 Thread.Sleep(TimeSpan.FromMilliseconds(123)); // waste time here
8 return a + b;
9 }
10 }
11 }
使用WCF扩展记录服务调用时间

此种方式简化了代码,但仍然需要在各自方法内实现,并需提供方法名作为参数。

使用 Message Inspection 来解决问题

我们定义类 IncomingMessageLoggerInspector 来实现 IDispatchMessageInspector 接口。

使用WCF扩展记录服务调用时间
 1     #region IDispatchMessageInspector Members
2
3 public object AfterReceiveRequest(
4 ref Message request,
5 IClientChannel channel,
6 InstanceContext instanceContext)
7 {
8 var context = OperationContext.Current;
9 if (context == null) return null;
10
11 var operationName = ParseOperationName(context.IncomingMessageHeaders.Action);
12
13 return MarkStartOfOperation(
14 context.EndpointDispatcher.ContractName, operationName,
15 context.SessionId);
16 }
17
18 public void BeforeSendReply(ref Message reply, object correlationState)
19 {
20 var context = OperationContext.Current;
21 if (context == null) return;
22
23 var operationName = ParseOperationName(context.IncomingMessageHeaders.Action);
24
25 MarkEndOfOperation(
26 context.EndpointDispatcher.ContractName, operationName,
27 context.SessionId, correlationState);
28 }
29
30 #endregion
使用WCF扩展记录服务调用时间

通过服务的当前上下文实例,我们可以获取到服务被调用的契约名称 ContractName,并且可以在 IncomingMessageHeaders 总解析出被调用的 OperationName。

我们在方法 MarkStartOfOperation 中启动 Stopwatch 开始测量执行时间,在方法执行完毕后服务模型会调用 BeforeSendReply 并将 Stopwatch 实例引用传递至 correlationState,此时我们可以在方法 MarkEndOfOperation 中解决时间测量,并打印日志。

使用WCF扩展记录服务调用时间
 1     #region Private Methods
2
3 private static string ParseOperationName(string action)
4 {
5 if (string.IsNullOrEmpty(action)) return action;
6
7 string actionName = action;
8
9 int index = action.LastIndexOf('/');
10 if (index >= 0)
11 {
12 actionName = action.Substring(index + 1);
13 }
14
15 return actionName;
16 }
17
18 private static object MarkStartOfOperation(
19 string inspectorType, string operationName, string sessionId)
20 {
21 var message = string.Format(CultureInfo.InvariantCulture,
22 "Operation [{0}] was called at [{1}] on [{2}] in thread [{3}].",
23 operationName, inspectorType,
24 DateTime.Now.ToString(@"yyyy-MM-dd HH:mm:ss.ffffff", CultureInfo.InvariantCulture),
25 Thread.CurrentThread.ManagedThreadId);
26
27 Debug.WriteLine(message);
28
29 return Stopwatch.StartNew();
30 }
31
32 private static void MarkEndOfOperation(
33 string inspectorType, string operationName,
34 string sessionId, object correlationState)
35 {
36 var watch = (Stopwatch)correlationState;
37 watch.Stop();
38
39 var message = string.Format(CultureInfo.InvariantCulture,
40 "Operation [{0}] returned after [{1}] milliseconds at [{2}] on [{3}] in thread [{4}].",
41 operationName, watch.ElapsedMilliseconds, inspectorType,
42 DateTime.Now.ToString(@"yyyy-MM-dd HH:mm:ss.ffffff", CultureInfo.InvariantCulture),
43 Thread.CurrentThread.ManagedThreadId);
44
45 Debug.WriteLine(message);
46 }
47
48 #endregion
使用WCF扩展记录服务调用时间

此时,我们需要定义 EndpointBehavior 来讲 Inspector 设置到 DispatchRuntime 中。

使用WCF扩展记录服务调用时间
 1   public class IncomingMessageLoggerEndpointBehavior : IEndpointBehavior
2 {
3 #region IEndpointBehavior Members
4
5 public void AddBindingParameters(
6 ServiceEndpoint endpoint,
7 BindingParameterCollection bindingParameters)
8 {
9 }
10
11 public void ApplyClientBehavior(
12 ServiceEndpoint endpoint,
13 ClientRuntime clientRuntime)
14 {
15 }
16
17 public void ApplyDispatchBehavior(
18 ServiceEndpoint endpoint,
19 EndpointDispatcher endpointDispatcher)
20 {
21 if (endpointDispatcher != null)
22 {
23 endpointDispatcher.DispatchRuntime.MessageInspectors.Add(
24 new IncomingMessageLoggerInspector());
25 }
26 }
27
28 public void Validate(ServiceEndpoint endpoint)
29 {
30 }
31
32 #endregion
33 }
使用WCF扩展记录服务调用时间

然后,我们在 ServiceHost 实例化后,未Open前,将 IncomingMessageLoggerEndpointBehavior 添加至 Endpoint 的 Behaviors 中。

使用WCF扩展记录服务调用时间
 1   class Program
2 {
3 static void Main(string[] args)
4 {
5 ServiceHost host = new ServiceHost(typeof(CalculatorService));
6
7 foreach (var endpoint in host.Description.Endpoints)
8 {
9 endpoint.Behaviors.Add(new IncomingMessageLoggerEndpointBehavior());
10 }
11
12 host.Opened += new EventHandler(delegate(object obj, EventArgs e)
13 {
14 Debug.WriteLine(typeof(CalculatorService).Name + " 服务已经启动!");
15 });
16
17 host.Open();
18
19 Console.ReadKey();
20 }
21 }
使用WCF扩展记录服务调用时间

使用 WcfTestClient.exe 调用服务,执行 2 + 3 查看结果,

使用WCF扩展记录服务调用时间

在 Debug 输出中可以看到,

使用WCF扩展记录服务调用时间

使用配置文件定制

使用配置文件定制扩展的优点就是可以按需添加和删除扩展,而无需改动代码。比如当发现系统有性能问题时,添加该扩展来查看具体哪个方法执行速度慢。

需要定义类来实现 BehaviorExtensionElement 抽象类。

使用WCF扩展记录服务调用时间
 1   public class IncomingMessageLoggerEndpointBehaviorExtension : BehaviorExtensionElement
2 {
3 public override Type BehaviorType
4 {
5 get { return typeof(IncomingMessageLoggerEndpointBehavior); }
6 }
7
8 protected override object CreateBehavior()
9 {
10 return new IncomingMessageLoggerEndpointBehavior();
11 }
12 }
使用WCF扩展记录服务调用时间

在配置文件中添加扩展项,

使用WCF扩展记录服务调用时间
1     <extensions>
2 <behaviorExtensions>
3 <add name="incomingMessageLogger"
4 type="WcfExtensibilityTestServiceConsole.Extensions.IncomingMessageLoggerEndpointBehaviorExtension, WcfExtensibilityTestServiceConsole"/>
5 </behaviorExtensions>
6 </extensions>
使用WCF扩展记录服务调用时间

在终结点行为中添加该扩展定义,

使用WCF扩展记录服务调用时间
 1     <behaviors>
2 <serviceBehaviors>
3 <behavior>
4 <serviceMetadata/>
5 <serviceDebug includeExceptionDetailInFaults="true"/>
6 </behavior>
7 </serviceBehaviors>
8 <endpointBehaviors>
9 <behavior>
10 <incomingMessageLogger/>
11 </behavior>
12 </endpointBehaviors>
13 </behaviors>
使用WCF扩展记录服务调用时间

使用 ServiceBehavior 扩展

同理,如果服务实现了多个 Endpoint,则想在所有 Endpoint 上添加该扩展,除了可以逐个添加或者使用 behaviorConfiguration 来配置。

另一个方法是可以借助 IServiceBehavior 的扩展实现。

使用WCF扩展记录服务调用时间
 1   public class IncomingMessageLoggerServiceBehavior : IServiceBehavior
2 {
3 #region IServiceBehavior Members
4
5 public void AddBindingParameters(
6 ServiceDescription serviceDescription,
7 ServiceHostBase serviceHostBase,
8 Collection<ServiceEndpoint> endpoints,
9 BindingParameterCollection bindingParameters)
10 {
11 }
12
13 public void ApplyDispatchBehavior(
14 ServiceDescription serviceDescription,
15 ServiceHostBase serviceHostBase)
16 {
17 if (serviceHostBase != null)
18 {
19 foreach (ChannelDispatcher channelDispatcher in serviceHostBase.ChannelDispatchers)
20 {
21 foreach (EndpointDispatcher endpointDispatcher in channelDispatcher.Endpoints)
22 {
23 endpointDispatcher.DispatchRuntime.MessageInspectors.Add(
24 new IncomingMessageLoggerInspector());
25 }
26 }
27 }
28 }
29
30 public void Validate(
31 ServiceDescription serviceDescription,
32 ServiceHostBase serviceHostBase)
33 {
34 }
35
36 #endregion
37 }
使用WCF扩展记录服务调用时间

原理相同,仅是遍历通道分配器中所有的终结点,逐一添加 Inspector。

同理,如果需要在配置文件中使用,也需要实现一个 BehaviorExtensionElement 类。

使用WCF扩展记录服务调用时间
 1   public class IncomingMessageLoggerServiceBehaviorExtension : BehaviorExtensionElement
2 {
3 public override Type BehaviorType
4 {
5 get { return typeof(IncomingMessageLoggerServiceBehavior); }
6 }
7
8 protected override object CreateBehavior()
9 {
10 return new IncomingMessageLoggerServiceBehavior();
11 }
12 }
使用WCF扩展记录服务调用时间

此时的配置文件描述如下:

使用WCF扩展记录服务调用时间
 1     <behaviors>
2 <serviceBehaviors>
3 <behavior>
4 <serviceMetadata/>
5 <serviceDebug includeExceptionDetailInFaults="true"/>
6 <incomingMessageLogger/>
7 </behavior>
8 </serviceBehaviors>
9 </behaviors>
10 <extensions>
11 <behaviorExtensions>
12 <add name="incomingMessageLogger"
13 type="WcfExtensibilityTestServiceConsole.Extensions.IncomingMessageLoggerServiceBehaviorExtension, WcfExtensibilityTestServiceConsole"/>
14 </behaviorExtensions>
15 </extensions>
使用WCF扩展记录服务调用时间

参考资料

标签: .NETWCFTCPExtensibility