一、为什么我们需要服务调用日志
在三个月前，我一个朋友他们公司的内部软件系统更新换代。在新系统中，用户有时会说慢，但是具体怎么慢，慢到什么程度也讲不清楚。问题难定位，从而更难解决。他们的新系统是CS模式，客户端使用的是WPF，服务端使用的是WCF。后来在他们的WCF服务中加了一个消息拦截器，在不影响现有的代码情况下，记录了WCF服务调用日志。可以清晰的记录哪个用户调用了服务，传的参数是什么，服务调用是什么时候调用的，服务耗时是多少，调用服务的过程中执行了哪些SQL语句，每个SQL耗时是多少等等。
有了这些日志帮助，可以非常容易的定位问题在哪里，从而大大的提高了用户体验度。
在很多的项目中，特别是.Net项目中，日志一般都是记录在本地文件中，但是这种日志非常难以阅读。如果将日志存储到数据库中，又影响系统性能，所以又不得不选择记录在本地，因为有日志总比没有日志强！
为了解决这一问题，我们可以搭建一个日志系统，该系统有独立的日志数据库，日志系统可以是Java、C#也可以是Node.js，因为日志系统只需要对接消息队列既可，消息队列可以是ActiveMQ、RabbitMQ、Kafaka等。而其他系统只需要将日志信息发送到消息队列即可，性能是非常的高。这就大大的解耦了系统之间的耦合度，运维人员也可以很方便的查看日志消息。
二、为什么我们需要使用WCF服务
在制造业中，特别是工厂内部使用的软件，小编认为还是CS的模式比较合适。小编曾给过几家制造业公司开发过BS和CS模式的项目，其中有一个项目的客户是一家汽车制造业公司，他们指定要BS模式的系统，小编开发了两三个月的时间，简直就是个噩梦。作为过来人，强烈建议使用CS模式开发制造业的生产系统。
CS相比较BS，有以下特点：
1、因为CS开发速度快，代码简单，客户端的代码也不会像HTML、CSS、JS那么难操作，对于那些擅长写服务端代码的人来说，难度会降低很多。
2、CS模式充分的利用了客户端的电脑性能，减轻服务端压力。
3、CS响应速度快，CS模式中客户端与服务端IO交互少，只需要交互数据，而BS中需要下载很多的HTML、CSS、JS文件。
在CS模式中，服务端建议使用WCF，虽然MVC API更出名，但是WCF更适合公司内部的项目开发。VS帮助我们开发者一键生成客户端调用代码，十分的便捷。
对于企业内部项目，如MES、仓库管理、品质监控、生产排程等系统，小编认为C#比Java更合适，CS比BS更合适，WCF比Mvc API 更合适。而权限管理、单点登录、报表、HR等系统，使用BS模式要更适合一些。在CS模式中，客户端是（Winform、WPF）可以内嵌网页。所以说，小编认为没有技术谁比谁好，只是在不同的业务场景下那个技术更合适而已。
三、WCF服务日志设计图
1、用户发送一个wcf的服务请求时，wcf的消息拦截器会拦截客户端发出的请求。
2、在消息拦截器中，首先触发的是AfterReceiveRequest方法，官方给出的说明：在已接收入站消息后将消息调度到应发送到的操作之前调用。
3、在AfterReceiveRequest方法执行结束之后，将会执行具体的服务接口，也就是我们所开发的业务接口。
4、在接口执行完毕之后，会触发拦截器中BeforeSendReply方法，该官方给出的说明：在操作已返回后发送回复消息之前调用。
5、在BeforeSendReply方法中，可以将所要记录的日志信息记录在本地并将日志信息发送到消息队列中。等待日志系统监听到日志消息。
6、日志系统监听到队列中有消息时，将消息从队列中拿出来并存储到对应的日志数据库中，方便查询分析。
四、运行效果图
为了测试方便，小编只在用户服务上加了消息拦截器，先看效果图，后面再上代码。
为了方便方便查看日志消息，小编做了一个可供查询日志的界面，每次服务调用信息都能详细的查看到，特别是接受时间、响应时间、以及耗时时间：
由于我的电脑屏幕只有13寸，不能完全显示出日志列表的数据，以下是列表的代码：
<dxlc:GroupBox Header="日志列表" Grid.Row="2"> <dxg:GridControl CustomColumnDisplayText="grid_CustomColumnDisplayText" ItemsSource="{Binding ServiceAuditInfoList, Mode=TwoWay}" SelectedItem="{Binding SelectedServiceAuditInfo, Mode=TwoWay}"> <dxg:GridControl.View> <dxg:TableView ShowGroupPanel="False" ShowFilterPanelMode="Never" AutoWidth="False" /> </dxg:GridControl.View> <dxg:GridColumn FieldName="Host" Header="服务器" Width="120" /> <dxg:GridColumn FieldName="Port" Header="端口号" Width="80" /> <dxg:GridColumn FieldName="ServiceUri" Header="服务全称" Width="150" /> <dxg:GridColumn FieldName="ServiceName" Header="服务名称" Width="110" /> <dxg:GridColumn FieldName="Action" Header="接口名" Width="80" /> <dxg:GridColumn FieldName="Realm" Header="客户端域名" Width="120" /> <dxg:GridColumn FieldName="UserIP" Header="客户端IP" Width="120" /> <dxg:GridColumn FieldName="UserName" Header="用户人姓名" Width="100" /> <dxg:GridColumn FieldName="ReceiveTime" Header="接收时间" Width="120"/> <dxg:GridColumn FieldName="SendTime" Header="响应时间" Width="120" /> <dxg:GridColumn FieldName="ThreadId" Header="线程编号" Width="120" /> <dxg:GridColumn FieldName="VisitId" Header="访问编号" Width="120" /> <dxg:GridColumn FieldName="ElapsedMilliseconds" Header="耗时(毫秒)" Width="100" /> </dxg:GridControl> </dxlc:GroupBox>
当我们有了这些服务调用的日志系统，我们可以做各种图表来分析我们的系统哪里有问题，那些服务耗时，对系统优化很有好处。
五、WCF服务消息拦截器
WCF服务中，.Net在System.ServiceModel.dll中给开发者提供了一个WCF服务自定义扩展的接口，具体如下：
1 using System.Collections.ObjectModel; 2 using System.ServiceModel.Channels; 3 4 namespace System.ServiceModel.Description 5 { 6 // 7 // 摘要: 8 // 提供一种在整个服务内修改或插入自定义扩展的机制，包括 System.ServiceModel.ServiceHostBase。 9 public interface IServiceBehavior 10 { 11 // 12 // 摘要: 13 // 用于向绑定元素传递自定义数据，以支持协定实现。 14 // 15 // 参数: 16 // serviceDescription: 17 // 服务的服务说明。 18 // 19 // serviceHostBase: 20 // 服务的宿主。 21 // 22 // endpoints: 23 // 服务终结点。 24 // 25 // bindingParameters: 26 // 绑定元素可访问的自定义对象。 27 void AddBindingParameters(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase, Collection<ServiceEndpoint> endpoints, BindingParameterCollection bindingParameters); 28 // 29 // 摘要: 30 // 用于更改运行时属性值或插入自定义扩展对象（例如错误处理程序、消息或参数拦截器、安全扩展以及其他自定义扩展对象）。 31 // 32 // 参数: 33 // serviceDescription: 34 // 服务说明。 35 // 36 // serviceHostBase: 37 // 当前正在生成的宿主。 38 void ApplyDispatchBehavior(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase); 39 // 40 // 摘要: 41 // 用于检查服务主机和服务说明，从而确定服务是否可成功运行。 42 // 43 // 参数: 44 // serviceDescription: 45 // 服务说明。 46 // 47 // serviceHostBase: 48 // 当前正在构建的服务主机。 49 void Validate(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase); 50 } 51 }
我们只需要将 IServiceBehavior 接口实现，并将WCF消息拦截器加入到服务的终结点中：
1 public class ServiceAuditAttribute : Attribute, IServiceBehavior 2 { 3 public void AddBindingParameters(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase, Collection<ServiceEndpoint> endpoints, BindingParameterCollection bindingParameters) 4 { 5 return; 6 } 7 public void ApplyDispatchBehavior(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase) 8 { 9 foreach (ChannelDispatcher dispatcherBase in serviceHostBase.ChannelDispatchers) 10 { 11 var channelDispatcher = dispatcherBase as ChannelDispatcher; 12 13 foreach (EndpointDispatcher endpointDispatcher in channelDispatcher.Endpoints) 14 { 15 endpointDispatcher.DispatchRuntime.MessageInspectors.Add(new MessageInspector()); 16 } 17 } 18 } 19 public void Validate(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase) 20 { 21 22 } 23 }
WCF消息拦截器的具体实现如下：
/// <summary> /// WCF消息拦截器 /// </summary> public class MessageInspector : IDispatchMessageInspector { /// <summary> /// 在已接收入站消息后将消息调度到应发送到的操作之前调用。 /// </summary> /// <param name="request">请求消息</param> /// <param name="channel">传入通道</param> /// <param name="instanceContext">当前服务实例</param> /// <returns>Stopwatch</returns> public object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext) { Stopwatch stw = Stopwatch.StartNew(); //TODO 日志代码 return stw; } /// <summary> /// 在操作已返回后发送回复消息之前调用 /// </summary> /// <param name="reply">回复消息。 如果操作是单向的，则此值为 null。</param> /// <param name="correlationState">计时器</param> public void BeforeSendReply(ref Message reply, object correlationState) { var watch = (Stopwatch)correlationState; watch.Stop(); //TODO 日志代码 } }
在这两个接口中，我们就可以自由发挥了。
1 ServiceAuditInfo serviceAuditInfo = new ServiceAuditInfo(); 2 serviceAuditInfo.Id = Guid.NewGuid().ToString(); 3 serviceAuditInfo.Host = context.IncomingMessageHeaders.To.Host; 4 serviceAuditInfo.Port = context.IncomingMessageHeaders.To.Port; 5 serviceAuditInfo.ServiceUri = context.IncomingMessageHeaders.To.LocalPath; 6 serviceAuditInfo.ServiceName = ParseUriLastPart(context.IncomingMessageHeaders.To.LocalPath); 7 serviceAuditInfo.Action = ParseUriLastPart(context.IncomingMessageHeaders.Action); 8 serviceAuditInfo.Realm = ApplicationContext.Current.UserVisitInfo.Realm; 9 serviceAuditInfo.UserIP = ApplicationContext.Current.UserVisitInfo.UserIP; 10 serviceAuditInfo.UserId = ApplicationContext.Current.UserVisitInfo.UserId; 11 serviceAuditInfo.UserName = ApplicationContext.Current.UserVisitInfo.UserName; 12 serviceAuditInfo.LoginToken = ApplicationContext.Current.UserVisitInfo.LoginToken; 13 serviceAuditInfo.VisitId = ApplicationContext.Current.UserVisitInfo.Id; 14 serviceAuditInfo.ThreadId = Thread.CurrentThread.ManagedThreadId.ToString(); 15 serviceAuditInfo.ReceiveTime = ApplicationContext.Current.UserVisitInfo.ReceiveTime; 16 serviceAuditInfo.SendTime = DateTime.Now; 17 serviceAuditInfo.ElapsedMilliseconds = (int)watch.ElapsedMilliseconds; 18 string logJson = JsonConvert.SerializeObject(serviceAuditInfo); 19 20 //发送消息 21 var publisher = new MQProducer("LogExchange", "localhost", 22 "guest", "guest", "/", new Uri("amqp://localhost/")); 23 24 publisher.PublishDirectMessage("ServiceAudit", logJson);
为了方便演示，我简化了消息队列的代码，生产环境中肯定是不能用这样的代码。至此我们就能将日志信息发送到RabbitMQ消息队列中。
五、应用
六、应用拦截器
我们只需要在服务实现类上加上【ServiceAudit】特性即可
启动程序，并登录，消息队列中就有了三条日志信息，等待被消费。由于消息队列中消息很快就会被消费掉，我停止了日志服务系统的服务。
如果我们启动日志服务，数据将会很快的被消费掉。毕竟，RabbitMQ是非常快的消息队列。
总结：
有了服务日志，我们可以再一步进行扩展，记录系统中执行的SQL语句，这样我们又能知道每次调用服务具体执行了那些SQL语句。日志系统可以给公司IT建设带来很大的便利。补充一句：网上的代码只是示例，具体应用到生产环境中还需要进一步的封装。