一般对于提供出来的接口,虽然知道在哪些业务场景下才会被调用,但是不知道什么时候被调用、调用的频率、接口性能,当出现问题的时候也不容易重现请求;为了追踪这些内容就需要把每次接口的调用信息给完整的记录下来,也就是记录日志。日志中可以把调用方ip、服务器ip、调用时间点、时长、输入输出都给完整的记录下来,有了这些数据,排查问题、重现异常、性能瓶颈都能准确的找到切入点。
这种功能,当然没人想要去在每个Operation里边插入一段代码,如果有类似AOP的玩意就再好不过了。
wcf中有IDispatchMessageInspector分发消息检查器这么个玩意,
1 namespace System.ServiceModel.Dispatcher 2 { 3 using System; 4 using System.ServiceModel; 5 using System.ServiceModel.Channels; 6 7 public interface IDispatchMessageInspector 8 {
// 接收请求后触发, 此方法的返回值将作为BeforeSendReply的第二个参数correlcationState传入 9 object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext);
// 在输出相应触发 10 void BeforeSendReply(ref Message reply, object correlationState); 11 } 12 }
下面是英文解释:
亦即允许我们对进出服务的消息进行检查和修改,这看起来有点像mvc的过滤器
执行过程: AfterReceiveRequest -> wcf操作 -> BeforeSendReply
切入点找到了,需要做的就是实现这个接口方法,记录日志,还可以计算一段时间内访问的次数并设置相应的阀值也就是可以实现并发限流,限流的目的主要是防止恶意调用维持己方服务器的稳定。
实现思路:
1 public class ThrottleDispatchMessageInspector : IDispatchMessageInspector 2 { 3 public object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext) 4 { 5 // [并发限流] 6 以ContractName+OperationName 作为MemoryCache的键,值为调用次数; 设置绝对过期时间 7 if(次数 > 设定的阀值) 8 request.Close(); 直接关闭请求 9 10 // [log] 记录请求输入消息、开始时间、服务器ip、客户端ip、 访问的wcf契约和方法... 11 LogVO log 12 // [log] 将日志实体作为返回值 13 return log; 14 15 } 16 public void BeforeSendReply(ref Message reply, object correlationState) { 17 //[log]补充完整log的属性: 请求结束时间, 调用时长... 然后将log丢入队列(不直接插数据库,防止日志记录影响接口性能) 慢慢落地rds中 18 var log = correlationState as LogVO; 19 log => Queue 20 } 21 }
完整的代码如下:
1 // 自定义分发消息检查器 2 public class ThrottleDispatchMessageInspector : IDispatchMessageInspector 3 { 4 //TODO 这两个参数根据系统的配置处理方式存储,作为示例就直接写了 5 public static int throttleNum = 10; // 限流个数 6 public static int throttleUnit = 4; // s 7 8 CacheItemPolicy policy = new CacheItemPolicy(); //! 过期策略,保证第一个set和之后set的绝对过期时间保持一致 9 10 #region implement IDispatchMessageInspector 11 12 // 此方法的返回值 将作为方法BeforeSendReply的第二个参数 object correlationState传入 13 public object AfterReceiveRequest(ref Message request, IClientChannel channel, InstanceContext instanceContext) 14 { 15 16 17 // 获取ContractName和OperationName 用来作为缓存键 18 var context = OperationContext.Current; 19 string contractName = context.EndpointDispatcher.ContractName; 20 string operationName = string.Empty; 21 if (context.IncomingMessageHeaders.Action == null) 22 { 23 operationName = request.Properties.Values.LastOrDefault().ToString(); 24 } 25 else 26 { 27 if (context.IncomingMessageHeaders.Action.Contains("/")) 28 { 29 operationName = context.IncomingMessageHeaders.Action.Split('/').LastOrDefault(); 30 } 31 } 32 string throttleCacheKey = contractName + "_" + operationName; 33 // 缓存当前请求频率, 以内存缓存System.Runtime.Caching.MemoryCache为例(.net4.0+) 34 ObjectCache cache = MemoryCache.Default; 35 var requestCount = cache.Get(throttleCacheKey); 36 int currRequestCount = 1; 37 if (requestCount != null && int.TryParse(requestCount.ToString(), out currRequestCount)) 38 { 39 // 访问次数+1 40 currRequestCount++; 41 cache.Set(throttleCacheKey, currRequestCount, policy); //必须保证过期策略和第一次set的时候一致,不然过期时间会有问题 42 } 43 else 44 { 45 policy.AbsoluteExpiration = DateTime.Now.AddSeconds(throttleUnit); 46 cache.Set(throttleCacheKey, currRequestCount, policy); 47 } 48 49 // 如果当前请求数大于阀值,直接关闭 50 if (currRequestCount > throttleNum) 51 { 52 request.Close(); 53 } 54 55 //作为返回值 传给BeforeSendReply 56 LogVO log = new LogVO 57 { 58 BeginTime = DateTime.Now, 59 ContractName = contractName, 60 OperationName = operationName, 61 Request = this.MessageToString(ref request), 62 Response = string.Empty 63 }; 64 return log; 65 } 66 67 public void BeforeSendReply(ref Message reply, object correlationState) 68 { 69 70 // 补充AfterReceiveRequest 传递过来的日志实体的属性, 记录 71 LogVO log = correlationState as LogVO; 72 log.EndTime = DateTime.Now; 73 log.Response = this.MessageToString(ref reply); 74 log.Duration = (log.EndTime - log.BeginTime).TotalMilliseconds; 75 76 //attention 为不影响接口性能,日志实体push进队列(redis .etc),然后慢慢落地 77 //TODO 这里直接写文本啦~ 78 try 79 { 80 string logPath = "D:\\WcfLog.txt"; 81 if (!File.Exists(logPath)) 82 { 83 File.Create(logPath); 84 } 85 StreamWriter writer = new StreamWriter(logPath, true); 86 writer.Write(string.Format("at {0} , {1} is called , duration: {2} \r\n", log.BeginTime, log.ContractName + "." + log.OperationName, log.Duration)); 87 writer.Close(); 88 } 89 catch (Exception ex) { } 90 } 91 #endregion 92 }