浅谈分布式项目日志监控

 目前公司项目采用dubbo服务化升级之后，原先大而全的几个主要应用，拆散重构成多个分布式服务。这个公司业务架构和系统架构实现一次升级，并发和业务开发效率得到提升。但是事情是两面的，引入dubbo服务化之后，导致业务链路过长，日志分散。不能在使用原来的日志处理方式了。 
   分布式情况下，每个日志分散到各自服务所在机器，日志的收集和分析使用原来古老的模式，肯定是过时了，集群和服务规模小还好，数量一大，我想不管是运维人员还是开发人员都会头疼。 
   目前处理这个需求最为火热的中间套件，自然首选是ELK，ELK是java技术栈的。也符合目前公司需求。ELK的安装就不讲述了，感兴趣的可以查看官网或者自行百度，资料还是挺多的。 
   确定了日志收集和分析的中间件，剩下一个就是日志埋点和怎么把日志串起来了。以前单个应用的时代，系统级别的日志可以通过aop解决。在分布式情况下对每一个独立服务而言，自身的日志系统还是通过aop解决，唯一需要的就是怎么把分散到各自不同应用的日志串起来。这个有个高大上的说法叫做业务链监控。 
   目前国内开源的产品有大众点评的cat，是整套业务链监控解决方案。对于我公司目前来说太重了，我这边日志已经有elk，就没必要在额外引入cat。那如何自己实现呢。 
   既然是链路，那自然有入口有出口。我们需要做的就是在入口出生成一个全局唯一的traceId，然后把这个traceId按照业务链路传递到各个服务中去。traceId就是一根线，把各个服务的日志串起来。注意一点，服务的时间要同步，因为是根据来时间排序的。 
   traceId的生成，简单方案可以采用uuid，其次推荐使用twiiter的snowflake算法。 
   traceId的传递，需要根据rpc框架来实现了。dubbo框架采用dubbo的fiter来实现，参考代码如下： 

Java代码  

1.   // 调用过程拦截  
2. public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {  
3.     //异步获取serviceId，没获取到不进行采样  
4.     String serviceId = tracer.getServiceId(RpcContext.getContext().getUrl().getServiceInterface());  
5.     if (serviceId == null) {  
6.         Tracer.startTraceWork();  
7.         return invoker.invoke(invocation);  
8.     }  
9.   
10.     long start = System.currentTimeMillis();  
11.     RpcContext context = RpcContext.getContext();  
12.     boolean isConsumerSide = context.isConsumerSide();  
13.     Span span = null;  
14.     Endpoint endpoint = null;  
15.     try {  
16.         endpoint = tracer.newEndPoint();  
17.           endpoint.setServiceName(serviceId);  
18.         endpoint.setIp(context.getLocalAddressString());  
19.         endpoint.setPort(context.getLocalPort());  
20.         if (context.isConsumerSide()) { //是否是消费者  
21.             Span span1 = tracer.getParentSpan();  
22.             if (span1 == null) { //为rootSpan  
23.                 span = tracer.newSpan(context.getMethodName(), endpoint, serviceId);//生成root Span  
24.             } else {  
25.                 span = tracer.genSpan(span1.getTraceId(), span1.getId(), tracer.genSpanId(), context.getMethodName(), span1.isSample(), null);  
26.             }  
27.         } else if (context.isProviderSide()) {  
28.             Long traceId, parentId, spanId;  
29.             traceId = TracerUtils.getAttachmentLong(invocation.getAttachment(TracerUtils.TID));  
30.             parentId = TracerUtils.getAttachmentLong(invocation.getAttachment(TracerUtils.PID));  
31.             spanId = TracerUtils.getAttachmentLong(invocation.getAttachment(TracerUtils.SID));  
32.             boolean isSample = (traceId != null);  
33.             span = tracer.genSpan(traceId, parentId, spanId, context.getMethodName(), isSample, serviceId);  
34.         }  
35.         invokerBefore(invocation, span, endpoint, start);//记录annotation  
36.         RpcInvocation invocation1 = (RpcInvocation) invocation;  
37.         setAttachment(span, invocation1);//设置需要向下游传递的参数  
38.         Result result = invoker.invoke(invocation);  
39.         if (result.getException() != null){  
40.             catchException(result.getException(), endpoint);  
41.         }  
42.         return result;  
43.     }catch (RpcException e) {  
44.         if (e.getCause() != null && e.getCause() instanceof TimeoutException){  
45.             catchTimeoutException(e, endpoint);  
46.         }else {  
47.             catchException(e, endpoint);  
48.         }  
49.         throw e;  
50.     }finally {  
51.         if (span != null) {  
52.             long end = System.currentTimeMillis();  
53.             invokerAfter(invocation, endpoint, span, end, isConsumerSide);//调用后记录annotation  
54.         }  
55.     }  
56. }  

  dubbo通过invocation.setAttachmen来在消费者和调用者之间传递traceId。 
  如果是http接口调用实现的rpc建议采用在request的head里面传递traceId。 
  在本地服务里面通过threadlocal变量来传递traceId。 
  如果想打印sql语句，通过orm框架的拦截器机制实现，以下是mybatis的参考代码 

Java代码  

1.   @Intercepts({ @Signature(type = Executor.class, method = "update", args = { MappedStatement.class, Object.class }),  
2.         @Signature(type = Executor.class, method = "query", args = { MappedStatement.class, Object.class,  
3.                 RowBounds.class, ResultHandler.class }) })  
4. public class MidaiLogMybatisPlugn implements Interceptor {  
5.     @Override  
6.     public Object intercept(Invocation invocation) throws Throwable {  
7.   
8.         Object result = null;  
9.         //从当前线程获取trace  
10.         MidaiLogTrace trace = MidaiLogTraceService.getMidaiLogTrace();  
11.         if(trace !=null){  
12.           Object[] arguments = invocation.getArgs();  
13.           MidaiLogTraceService.traceSqlLog(trace.getTraceId(), getSqlStatement(arguments));  
14.         }  
15.         try {  
16.             result = invocation.proceed();        
17.         } catch (Exception e) {  
18.             throw e;  
19.         }  
20.         return result;  
21.     }  
22.   
23.     @Override  
24.     public Object plugin(Object target) {  
25.         return Plugin.wrap(target, this); // mybatis提供的包装工具类  
26.     }  
27.   
28.     @Override  
29.     public void setProperties(Properties properties) {  
30.     }  
31.   
32.     private String getSqlStatement(Object[] arguments) {  
33.         MappedStatement mappedStatement = (MappedStatement) arguments[0];  
34.         Object parameter = null;  
35.         if (arguments.length > 1) {  
36.             parameter = arguments[1];  
37.         }  
38.         String sqlId = mappedStatement.getId();  
39.         BoundSql boundSql = mappedStatement.getBoundSql(parameter);  
40.         Configuration configuration = mappedStatement.getConfiguration();  
41.         String sql = showSql(configuration, boundSql);  
42.         StringBuilder str = new StringBuilder(100);  
43.         str.append(sqlId);  
44.         str.append(":");  
45.         str.append(sql);  
46.         str.append(":");  
47.         return str.toString();  
48.     }  
49.   
50.     public String showSql(Configuration configuration, BoundSql boundSql) {  
51.         Object parameterObject = boundSql.getParameterObject();  
52.         List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();  
53.         String sql = boundSql.getSql().replaceAll("[\\s]+", " ");  
54.         if (parameterMappings.size() > 0 && parameterObject != null) {  
55.             TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry();  
56.             if (typeHandlerRegistry.hasTypeHandler(parameterObject.getClass())) {  
57.                 sql = sql.replaceFirst("\\?", getParameterValue(parameterObject));  
58.   
59.             } else {  
60.                 MetaObject metaObject = configuration.newMetaObject(parameterObject);  
61.                 for (ParameterMapping parameterMapping : parameterMappings) {  
62.                     String propertyName = parameterMapping.getProperty();  
63.                     if (metaObject.hasGetter(propertyName)) {  
64.                         Object obj = metaObject.getValue(propertyName);  
65.                         sql = sql.replaceFirst("\\?", getParameterValue(obj));  
66.                     } else if (boundSql.hasAdditionalParameter(propertyName)) {  
67.                         Object obj = boundSql.getAdditionalParameter(propertyName);  
68.                         sql = sql.replaceFirst("\\?", getParameterValue(obj));  
69.                     }  
70.                 }  
71.             }  
72.         }  
73.         return sql;  
74.     }  
75.   
76.     private static String getParameterValue(Object obj) {  
77.         String value = null;  
78.         if (obj instanceof String) {  
79.             value = "‘" + obj.toString() + "‘";  
80.         } else if (obj instanceof Date) {  
81.             DateFormat formatter = DateFormat.getDateTimeInstance(DateFormat.DEFAULT, DateFormat.DEFAULT, Locale.CHINA);  
82.             value = "‘" + formatter.format(new Date()) + "‘";  
83.         } else {  
84.             if (obj != null) {  
85.                 value = obj.toString();  
86.             } else {  
87.                 value = "";  
88.             }  
89.   
90.         }  
91.         return value;  
92.     }  
93. }  

    当系统并发达到一定数量级，log4j日志打印本身会成为瓶颈，这个时候需要mq来解耦了，不在打印日志，而是发送mq消息，由mq消费端处理。因为目前公司项目并发数量还不足以导致该问题，因此尚未采用。 
    elk收集日志之后，通过kibana可以提供搜索。 
    

    剩下最后的工作量就是提供一个web界面来更好的分析和展示数据。