通过扩展 dubbo Filter, 拦截 RPC 请求的方式, 将在请求 API 时通过 SnowFlake 算法生成的全局唯一 traceId 存入到 RpcContext 中, 传递给下一个服务.
dubbo 服务调用日志
通过扩展 dubbo Filter, 拦截 RPC 请求的方式, 将在请求 API 时通过 SnowFlake 算法生成的全局唯一 traceId 存入到 RpcContext 中, 传递给下一个服务.
业务日志
通过 Load Time wearing 技术自动埋点, 在进入方法时, 通过 MDC 获取 traceId
接入追踪系统
dubbo 追踪接入
1 2 3 4 5 6 <!-- xxx-service pom.xml 引入 日志追踪插件 --> <dependency> <groupId>com.xxx</groupId> <artifactId>xxx-trace-client</artifactId> <version>0.2</version> </dependency>
http 追踪接入
1 2 3 4 5 6 7 8 9 <!-- web.xml 添加 --> <filter> <filter-name>controllerFilter</filter-name> <filter-class>com.xxx.trace.client.rest.LoggerFilter</filter-class> </filter> <filter-mapping> <filter-name>controllerFilter</filter-name> <url-pattern>/*</url-pattern> </filter-mapping>
方法日志自动埋点
1 2 3 4 5 6 7 8 9 10 11 12 13 14 <!-- META-INFO/aop.xml--> <?xml version="1.0" encoding="UTF-8"?> <aspectj> <weaver> <!-- only weave classes in your application-specific packages --> <include within="com.xxx.server.rest.resource.impl.*"/> </weaver> <aspects> <!-- weave in just these aspects --> <!--<aspect name="com.xxx.trace.client.aspect.ProfilingAspect"/>--> <aspect name="com.xxx.server.rest.aspect.ProfilingAspect"/> <aspect name="com.xxx.server.rest.aspect.TraceAspect"/> </aspects> </aspectj>
实现原理 自动埋点 自动埋点使用 代码织入 (AOP)
代码织入实现方式
静态代理
AspectJ 织入器 weaver)
compile-time weaving 使用 aspectj 编译器进行编译源码
post-compile weaving 对 class 文件进行织入
load-time weaving(LTW) 当 class loader 加载类的时候,进行织入
动态代理
JDK 动态代理 (接口)
CGlib(类)
这里使用 Load Time wearing 实现, 这种方式在类加载器织入代码.编译器织入 , 会造成编译速度变慢, 而且必须使用 ajc 编译器动态代理 会生成大量代理类, 加速内存消耗 使用 类加载期织入 相对于其他两种方式, 更加轻便.
具体实现
定义切面 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 @Aspect public class TraceAspect { private static final Logger log = LoggerFactory.getLogger(TraceAspect.class); @Pointcut("execution(* com.xxx.server.rest.resource.impl..*.*(..))") public void profileMethod() { } @Around("profileMethod()") public Object profile(ProceedingJoinPoint jp) { Object result = ""; String methodName = jp.getSignature().getName(); log.error("前置通知"); // 执行目标方法 try { // 前置通知 log.error("The method " + methodName + " begins with " + Arrays.asList(jp.getArgs())); result = jp.proceed(); // 返回通知 log.error("The method " + methodName + " ends with " + Arrays.asList(jp.getArgs())); } catch (Throwable e) { // 异常通知 log.error("The method " + methodName + " occurs expection : " + e); throw new RuntimeException(e); } log.error("get MDC {}", MDC.get(Span.TRACE_ID)); return result; } }
准备 aop.xml 这个文件要求放在 META-INF/aop.xml 路径下,以告知 AspectJ Weaver 我们需要把 ProfilingAspect 织入到应用的哪些类中
1 2 3 4 5 6 7 8 9 10 11 12 13 <?xml version="1.0" encoding="UTF-8"?> <aspectj> <weaver> <!-- only weave classes in your application-specific packages --> <include within="com.xxx.server.rest.resource.impl.*"/> <!-- 必须包含切面的路径 --> <include within="com.xxx.trace.client.aspect.*"/> </weaver> <aspects> <!-- weave in just these aspects --> <aspect name="com.xxx.trace.client.aspect.TraceAspect"/> </aspects> </aspectj>
maven 依赖 1 2 3 4 5 6 7 8 9 10 <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjweaver</artifactId> <version>1.8.9</version> </dependency> <dependency> <groupId>org.springframework</groupId> <artifactId>spring-aop</artifactId> <version>${spring-version}</version> </dependency>
配置 applicationContext.xml aspectj-weaving = on / off / auto-detect 如果设置为 auto-detect(默认), spring 将会在 classpath 中查找 aspejct 需要的 META-INF/aop.xml, 如果找到则开启 aspectj weaving
1 <context:load-time-weaver aspectj-weaving="autodetect"/>
VM 参数 开发时, idea 设置
tomcat7
1 2 -javaagent:/path/to/spring-instrument-4.3.3.RELEASE.jar -javaagent:/path/to/aspectjweaver-1.8.9.jar
tomcat8
1 -javaagent:/path/to/aspectjweaver-1.8.9.jar
tomcat 设置 javaagent catalina.sh 最前面添加
1 JAVA_OPTS="-javaagent:/path/to/spring-instrument-4.3.3.RELEASE.jar -javaagent:/path/to/aspectjweaver-1.8.9.jar"
调用链日志 扩展 Filter @Activate 是一个 Duboo 框架提供的注解。在 Dubbo 官方文档上有记载: 对于集合类扩展点,比如:Filter, InvokerListener, ExportListener, TelnetHandler, StatusChecker 等, 可以同时加载多个实现。 主要用处是标注在插件接口实现类上,用来配置该扩展实现类激活条件。 在 Dubbo 框架里面的 Filter 的各种实现类都通过 Activate 标注,用来描述该 Filter 什么时候生效。
用 @Activate 来实现一些 Filter ,可以具体如下:
无条件自动激活
直接使用默认的注解即可
1 2 3 4 5 6 7 import com.alibaba.dubbo.common.extension.Activate; import com.alibaba.dubbo.rpc.Filter; @Activate // 无条件自动激活 public class XxxFilter implements Filter { // ... }
配置 xxx 参数,并且参数为有效值时激活,比如配了 cache=”lru”,自动激活 CacheFilter
1 2 3 4 5 6 import com.alibaba.dubbo.common.extension.Activate; import com.alibaba.dubbo.rpc.Filter; @Activate("xxx") // 当配置了 xxx 参数,并且参数为有效值时激活,比如配了 cache="lru",自动激活 CacheFilter。 public class XxxFilter implements Filter { // ... }
只对提供方激活,group 可选 provider 或 consumer
1 2 3 4 5 6 7 8 import com.alibaba.dubbo.common.extension.Activate; import com.alibaba.dubbo.rpc.Filter; @Activate(group = {Constants.PROVIDER, Constants.CONSUMER}) // 只对提供方激活,group 可选"provider"或"consumer" public class XxxFilter implements Filter { // ... }
在 resourves/META-INF/dubbo/com.alibaba.dubbo.prc.Filter
文件中添加自定义 Filter 全类名
1 tracingFilter=com.xxx.trace.client.dubbo.TracingFilter
自定义参数在 RPC 请求的传递 使用 aop, 在 调用 dubbo 服务之前, 通过 RpcContext.getContext().setAttachments
保存自定义参数 在服务端使用 RpcContext.getContext().getAttachment
获取自定义参数
RpcContext 是一个 ThreadLocal 的临时状态记录器,当接收到 RPC 请求,或发起 RPC 请求 时,RpcContext 的状态都会变化。比如:A 调 B,B 再调 C,则 B 机器上,在 B 调 C 之 前,RpcContext 记录的是 A 调 B 的信息,在 B 调 C 之后,RpcContext 记录的是 B 调 C 的 信息。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 /** * 在调用 service 的接口之前,加入一些 dubbo 的隐式参数 * 2017-12-13 17:34 dong4j */ @Aspect @Component public class DubboServiceContextAop { @Pointcut("execution(* com.xxx.xxx.service.*.*(..))") public void serviceApi() { } @Before("serviceApi()") public void dubboContext(JoinPoint jp) { Map<String, String> context = new HashMap<>(); // todo you want do RpcContext.getContext().setAttachments(context); } }
1 2 3 4 5 6 7 8 9 public class DubboContextFilter implements Filter { @Override public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException { String var= RpcContext.getContext().getAttachment( 从 Aop 中放入的); // todo 其他相关处理 return invoker.invoke(invocation); } }
RpcContext 相关 API
1 2 3 4 5 6 7 8 9 10 // 远程调用 xxxService.xxx(); // 本端是否为消费端,这里会返回 true boolean isConsumerSide = RpcContext.getContext().isConsumerSide(); // 获取最后一次调用的提供方 IP 地址 String serverIP = RpcContext.getContext().getRemoteHost(); // 获取当前服务配置信息,所有配置信息都将转换为 URL 的参数 String application = RpcContext.getContext().getUrl().getParameter("application"); // 注意:每发起 RPC 调用,上下文状态会变化 yyyService.yyy();
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 public class XxxServiceImpl implements XxxService { public void xxx() { // 本端是否为提供端,这里会返回 true boolean isProviderSide = RpcContext.getContext().isProviderSide(); // 获取调用方 IP 地址 String clientIP = RpcContext.getContext().getRemoteHost(); // 获取当前服务配置信息,所有配置信息都将转换为 URL 的参数 String application = RpcContext.getContext().getUrl().getParameter("applicatio n"); // 注意:每发起 RPC 调用,上下文状态会变化 yyyService.yyy(); // 此时本端变成消费端,这里会返回 false boolean isProviderSide = RpcContext.getContext().isProviderSide(); } }
traceId 的传递过程 生成 traceId 在处理前端请求之前, 使用 LoggerFilter
拦截请求, 通过 SnowFlake 生成 traceId, 并存入 MDC 中
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 @Slf4j public class LoggerFilter extends AbstractRequestLoggingFilter { @Override protected void doFilterInternal (HttpServletRequest request, HttpServletResponse response, final FilterChain filterChain) throws ServletException, IOException { final String traceId = "" + new SnowflakeId (0 ).generate(); MDC.put(Span.TRACE_ID, traceId); ... super .doFilterInternal(request, response, filterChain); ... log.error(ApiLog.buildApiLog(EventType.invoke_interface, request.getRequestURI(), request.getHeader("token" ), response.getStatus(), EventLog.MONITOR_STATUS_SUCCESS, "我是mock api成功日志" ).toString()); MDC.remove(Span.TRACE_ID); } @Override protected void beforeRequest (HttpServletRequest request, String message) { } @Override protected void afterRequest (HttpServletRequest request, String message) { } }
服务间传递 traceId 存放在 MDC 中的值只有在同一个线程中才能共享, 当发起 Rpc 调用后, 肯定不是同一个线程, 因此使用 RpcContext 来传递 Rpc traceId
服务调用之前, 消费者端
通过 RpcContext.getContext().setAttachments("traceId",MDC.get("traceId"))
将 traceId 存入 RpcContext
服务调用之后, 提供者端
通过 RpcContext.rpcContext.getAttachment("traceId")
从 RpcContext 中获取 traceId, 并使用 MDC.put("traceId", traceId)
将 traceId 存入当前线程中, 便于业务日志打印
删除 traceId 请求完成后, dubbo 服务线程自动销毁, 只需要在 LoggerFilter
中调用 MDC.clear()
清除 MDC
传输日志 kafka
http://blog.csdn.net/honglei915/article/details/37563647
动态修改日志级别 这里选择使用 JMX 来实现日志级别动态修改.
具体实现 监听容器启动 当容器启动时, 获取应用名, 然后创建 zookeeper 临时节点
以前使用 ServerListener
实现, 但是这种方式需要修改 web.xml, 添加一个自定义 ServerListener 监听器.
这里重构下, 将监听容器启动然后创建 zookeeper 节点的逻辑迁入到 xxx-trace 模块中
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 @Component @Slf4j public class ApplicationEventHandle implements ApplicationListener , ApplicationContextAware { @Autowired private TraceConfig traceConfig; @Autowired private ServletContext servletContext; @Override public void setApplicationContext (ApplicationContext applicationContext) throws BeansException { } @Override public void onApplicationEvent (ApplicationEvent applicationEvent) { if (applicationEvent instanceof ContextRefreshedEvent) { ContextRefreshedEvent contextRefreshedEvent = (ContextRefreshedEvent) applicationEvent; if (contextRefreshedEvent.getApplicationContext().getParent()== null ) { log.error("spring 容器初始化完成: {}" , applicationEvent.getClass()); DynamicChangeLogLevel.initZookeeperNode(traceConfig.getZookeeperHost(), servletContext .getServletContextName()); } } else if (applicationEvent instanceof ContextStartedEvent) { log.error("应用启动事件: {}" , applicationEvent.getClass()); } else if (applicationEvent instanceof ContextStoppedEvent) { log.error("应用停止事件: {}" , applicationEvent.getClass()); LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); loggerContext.stop(); } else if (applicationEvent instanceof ContextClosedEvent) { log.error("应用关闭事件: {}" , applicationEvent.getClass()); } else { log.error("其他事件: {}" , applicationEvent.getClass()); } } }
zk 节点组成
loglevel
applicationName1
serviceHost1:servicePort1 –> data = defaultLogLevel
serviceHost2:servicePort2 –> data = defaultLogLevel
applicationName2
serviceHost1:servicePort1 –> data = defaultLogLevel
root 节点下, 根据 应用名 区分不同应用 集群部署时, 相同应用名根据 host 和 port 区分, 修改某个节点, 不会影响其他节点.
其他模块接入 pom.xml 配置
添加 name
标签, 用于统一标识应用名, 使用 ${project.name}
获取 name
值
比如在 logback.xml 中, 向 JMX 注册 MBean, 需要标识当前应用名 logback.xml 配置
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 <?xml version="1.0" encoding="UTF-8" ?> <configuration > <contextName > ${project.name}</contextName > <jmxConfigurator /> <statusListener class ="ch.qos.logback.core.status.OnConsoleStatusListener" /> <appender name ="STDOUT" class ="ch.qos.logback.core.ConsoleAppender" > <encoder > <pattern > [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%thread] %-5level %logger{5} - %X{traceId} - %X{platformType} - %X{clientVersion} - %msg%n </pattern > <charset > UTF-8</charset > </encoder > </appender > <root level ="DEBUG" > <appender-ref ref ="STDOUT" /> </root > <logger name ="com.xxx" level ="DEBUG" /> </configuration >
只需要在 web.xml 添加以下配置, 用于标识当前应用
1 2 3 4 5 <display-name > 应用名 </display-name > <context-param > <param-name > webAppRootKey</param-name > <param-value > 应用名 </param-value > </context-param >
为了便于管理应用名, 这里使用 pom.xml 中的 name 标签来设置 web.xml 中的设置
在 pom.xml 中添加 maven-war-plugin
插件
1 2 3 4 5 6 7 8 9 10 11 12 13 <plugin > <groupId > org.apache.maven.plugins</groupId > <artifactId > maven-war-plugin</artifactId > <version > 2.6</version > <configuration > <webResources > <resource > <directory > src/main/webapp</directory > <filtering > true</filtering > </resource > </webResources > </configuration > </plugin >
然后 web.xml 的配置就可以修改为
1 2 3 4 5 <display-name > ${project.name}</display-name > <context-param > <param-name > webAppRootKey</param-name > <param-value > ${project.name}</param-value > </context-param >
最后在 applicationContext.xml 引入 xxx-config.xml
1 <import resource="classpath:xxx-config.xml"/>
日志节点监控和修改日志接口 监控 接口
获取所有应用列表
应用的当前日志级别 (root, com.xxx)
修改某个应用的日志 (root, com.xxx)
修改全部应用的日志 (root, com.xxx)
重置全部日志级别
日志类型
日志类型
说明
normal
正常入库日志
invoke_interface
api 调用日志
middleware_opt
中间件操作日志 (目前仅支持 hbase 和 mongo)
job_execute
job 执行日志
rpc_trace
rpc trace 跟踪日志
custom_log
自定义埋点日志
thirdparty_call
第三方系统调用日志
正常日志
api 日志 1 2 3 // 参数依次为 EventType(事件类型)、api、账号、请求耗时、成功还是失败、具体自定义的日志内容 LOGGER.info(ApiLog.buildApiLog(EventType.invoke_interface, "/app/status", "800001", 100, EventLog.MONITOR_STATUS_SUCCESS, "我是mock api成功日志").toString()); LOGGER.info(ApiLog.buildApiLog(EventType.invoke_interface, "/app/status", "800001", 10, EventLog.MONITOR_STATUS_FAILED, "我是mock api失败日志").toString());
中间件日志 1 2 3 // 参数依次为 EventType(事件类型)、MiddleWare(中间件名称)、操作耗时、成功还是失败、具体自定义的日志内容 LOGGER.info(EventLog.buildEventLog(EventType.middleware_opt, MiddleWare.HBASE.symbol(), 100, EventLog.MONITOR_STATUS_SUCCESS, "我是mock middle ware成功日志").toString()); LOGGER.info(EventLog.buildEventLog(EventType.middleware_opt, MiddleWare.MONGO.symbol(), 10, EventLog.MONITOR_STATUS_FAILED, "我是mock middle ware失败日志").toString());
job 执行日志 1 2 // job 执行仅仅处理失败的日志(成功的不做处理,所以只需要构造失败的日志), 参数依次为 EventType(事件类型)、job 的 id 号、操作耗时、失败、具体自定义的日志内容 LOGGER.info(EventLog.buildEventLog(EventType.job_execute, "application_1477705439920_0544", 10, EventLog.MONITOR_STATUS_FAILED, "我是mock job exec失败日志").toString());
第三方请求日志 1 2 3 4 5 // 参数依次为 EventType(事件类型)、第三方名称、操作耗时、成功还是失败、具体自定义的日志内容 LOGGER.info(EventLog.buildEventLog(EventType.thirdparty_call, "xx1", 100, EventLog.MONITOR_STATUS_FAILED, "我是mock third 失败日志").toString()); LOGGER.info(EventLog.buildEventLog(EventType.thirdparty_call, "xx1", 100, EventLog.MONITOR_STATUS_SUCCESS, "我是mock third 成功日志").toString()); LOGGER.info(EventLog.buildEventLog(EventType.thirdparty_call, "xx2", 100, EventLog.MONITOR_STATUS_SUCCESS, "我是mock third 成功日志").toString()); LOGGER.info(EventLog.buildEventLog(EventType.thirdparty_call, "xx2", 100, EventLog.MONITOR_STATUS_FAILED, "我是mock third 失败日志").toString());