作用
再微服务中 服务调用服务很常见。服务中相互调用链路追踪的尤为重要,能够帮助我们再异常时分析出哪个服务出了异常。以及各个链路中相互调用所消耗时间,通过这些数据能够帮助我们分析出各个服务的性能瓶颈
简单例子
在之前的provider和consumer的基础上进行修改
1.consumer接口添加一个日志打印
@RequestMapping("/findById")
@ResponseBody
public User findById(Integer id) {
logger.info("consumer:findById");
return userService.findById(id);
}
2.consumer调用provider的指定接口也添加一个日志打印
@RequestMapping("/findById")
@ResponseBody
public User findById(Integer id) {
logger.info("provider:findByid");
return users.stream().filter(c -> c.getId().intValue() == id.intValue()).findAny().get();
}
访问consumer查看日志打印
现在我们添加sleuth依赖
<!--sleuth链路跟踪-->
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
再观察日志
跟没引入sleuth之前多了这么一串
第一个参数 为服务名对应application.name
第二个参数 叫traceId(它表示一个请求的链路id)
第三个参数 叫spanId(表示链路上的每一个基本的工作单元)
第四个参数 表示是否输出到Zipkin等服务中来收集和展示 这里为false 等后面整合zipKin会用到
跟踪原理
当请求发送到分布式服务的入口端时(我们这里入口是consumer) 会创建一个TraceId 并在微服务中相互请求时通过报文head一直流转下去 通过TraceId能够实现整条链路的跟踪
为了统计每个单元的处理时间每个单元都有一个spanId spanId记录了请求开始时间戳和请求结束时间的时间戳 通过它我们可以知道每个单元的处理时间而找到性能瓶颈
查看更多日志信息
logging:
level:
org:
springframework:
web:
servlet:
DispatcherServlet: DEBUG
参数可以看到更多日志信息
抽样采集
在高并发请求下 如果每个请求都像上面一样记录日志并保存起来 会对性能产生影响 所以sleuth提供一个阀值 默认是0.1 10个请求只抽取一个来记录日志用于性能分析
通过设置以下参数
spring:
sleuth:
sampler:
probability: 1 #采集量 默认0.1 1为100% 但是会对性能影响 测试阶段使用
调试阶段可设置为1.上线后慢慢减少
自定义抽样采集
sleuth的抽样采集是使用Sampler 接口实现的 我们可以自定义
public abstract class Sampler {
public abstract boolean isSampled(long var1);
public static Sampler create(float rate) {
return CountingSampler.create(rate);
}
}
默认是使用PercentageBasedSarnpler 我们可以通过实现Sampler自定义抽样采集 并通过部署
整合Logstash
在分布式上 我们的服务是集群的同时各个微服务散落在不同的服务器上。如果我们需要分析日志是很困难和繁琐的我们可以通过Logstash对日志进行收集
1.在consumer和provider添加pom依赖
<dependency>
<groupId>net.logstash.logback</groupId>
<artifactId>logstash-logback-encoder</artifactId>
<version>5.1</version>
</dependency>
2.resources添加一个名为logback.xml
<?xml version="1.0" encoding="UTF-8"?>
<!--该日志将日志级别不同的log信息保存到不同的文件中 -->
<configuration>
<include resource="org/springframework/boot/logging/logback/defaults.xml" />
<springProperty scope="context" name="springAppName"
source="spring.application.name" />
<!-- 日志在工程中的输出位置 -->
<property name="LOG_FILE" value="${BUILD_FOLDER:-build}/${springAppName}" />
<!-- 控制台的日志输出样式 -->
<property name="CONSOLE_LOG_PATTERN"
value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}" />
<!-- 控制台输出 -->
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
<!-- 日志输出编码 -->
<encoder>
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
<charset>utf8</charset>
</encoder>
</appender>
<!-- 为logstash输出的JSON格式的Appender -->
<appender name="logstash"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_FILE}.json</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!--日志文件输出的文件名 -->
<fileNamePattern>${LOG_FILE}.json.%d{yyyy-MM-dd}.gz</fileNamePattern>
<!--日志文件保留天数 -->
<MaxHistory>3</MaxHistory>
</rollingPolicy>
<!-- 日志输出编码 -->
<encoder
class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
<providers>
<timestamp>
<timeZone>UTC</timeZone>
</timestamp>
<pattern>
<pattern>
{
"severity": "%level",
"service": "${springAppName:-}",
"trace": "%X{X-B3-TraceId:-}",
"span": "%X{X-B3-SpanId:-}",
"exportable": "%X{X-Span-Export:-}",
"pid": "${PID:-}",
"thread": "%thread",
"class": "%logger{40}",
"rest": "%message"
}
</pattern>
</pattern>
</providers>
</encoder>
</appender>
<!-- 日志输出级别 -->
<root level="INFO">
<appender-ref ref="console" />
<appender-ref ref="logstash" />
</root>
</configuration>
这里我们只是看效果 在项目下输出一个json文件 可以指定输出到mysql stash服务端 输出到ElasticSearch 相应配置百度
启动访问会在项目目录下输出json文件里面就包含日志信息
遇到过的问题
没有日志输出(排查是日志文件没生效)
https://www.jb51.net/article/132619.htm
启动报错
Exception in thread "main" java.lang.AbstractMethodError
at ch.qos.logback.core.OutputStreamAppender.encoderInit(OutputStreamAppender.java:180)
at ch.qos.logback.core.OutputStreamAppender.setOutputStream(OutputStreamAppender.java:171)
at ch.qos.logback.core.FileAppender.openFile(FileAppender.java:206)
at ch.qos.logback.core.FileAppender.start(FileAppender.java:127)
at ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:100)
at ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:90)
at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:309)
at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:193)
at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:179)
at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:165)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:152)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:110)
at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150)
at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)
at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
at org.slf4j.LoggerFactory.bind(LoggerFactory.java:150)
at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:124)
at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:412)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:357)
at org.apache.logging.slf4j.SLF4JLoggerContext.getLogger(SLF4JLoggerContext.java:39)
at org.apache.commons.logging.LogFactory$Log4jLog.<init>(LogFactory.java:204)
at org.apache.commons.logging.LogFactory$Log4jDelegate.createLog(LogFactory.java:166)
at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:109)
at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:99)
at org.springframework.boot.SpringApplication.<clinit>(SpringApplication.java:198)
at com.liqiang.provider.SpringCloudProviderApplication.main(SpringCloudProviderApplication.java:12)
改版本
整合Zipkin
Zipkin服务端搭建
1.创建一个名为spring-cloud-zipkin-server的spring boot项目
2.引入pom依赖
<dependency>
<groupId>io.zipkin.java</groupId>
<artifactId>zipkin-server</artifactId>
<version>2.8.4</version>
</dependency>
<dependency>
<groupId>io.zipkin.java</groupId>
<artifactId>zipkin</artifactId>
<version>2.8.4</version>
</dependency>
<dependency>
<groupId>io.zipkin.zipkin2</groupId>
<artifactId>zipkin</artifactId>
<version>2.8.4</version>
</dependency>
<dependency>
<groupId>io.zipkin.java</groupId>
<artifactId>zipkin-autoconfigure-ui</artifactId>
<version>2.8.4</version>
</dependency>
3.启动类添加注解
@SpringBootApplication
@EnableZipkinServer
public class SpringCloudZipkinServerApplication {
public static void main(String[] args) {
SpringApplication.run(SpringCloudZipkinServerApplication.class, args);
}
}
4.配置文件修改
spring:
application:
name: zipkinServer
server:
port: 9441
#解决报错java.lang.IllegalArgumentException: Prometheus requires that all meters with the same name have the same set of tag keys.
#There is already an existing meter containing tag keys [method, status, uri]. The meter you are attempting to register has keys [exception, method, status, uri].
management:
metrics:
web:
server:
auto-time-requests: false
5.启动访问http://127.0.0.1:9441/zipkin/
客户端
在之前的provider和consumer基础上进行修改
1.引入pom依赖
<!--sleuth链路跟踪-->
<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
2.application.yml增加zipkin服务端地址
spring:
zipkin:
base-url: http://127.0.0.1:9441 #zipkin服务端地址
3.设置收集基数为1 100%收集 方便看效果
spring:
sleuth:
sampler:
probability: 1
4.启动zipkin服务端 和provider和consumer 对consumer发起请求
zipkin核心组件
Collector
收集器组件, 它主要处理从外部系统发送过来的跟踪信息, 将这些信息转换为zipkin内部处理span格式以支持后续的存储 分析 展示等功能
storage
负责将收到的Collector处理过的数据存储到起来 默认是存储到内存中 可以通过使用其他组件 存到数据库
RESTfulAPI
主要提供给外部访问接口 用于外部系统展示跟踪信息或外接系统实现监控
WebUI
个人理解就是我们上面看到的管理界面
代码里面获得Trace信息
需求
如异常日志使用kibanna 收集日志不是有序的 所以我需要在异常过滤器每一行异常信息都加上TraceId通过搜索方式快速查询到这个链路的异常信息
private String writerLog(Exception e){
String errorCode = null;
if(breadcrumb!=null){
errorCode="[TraceId:"+breadcrumb.getTracerId()+",SpanId:"+breadcrumb.getSpanId()+",parent:"+breadcrumb.getParentId()+"]";
}else{
errorCode= UUIDUtils.create().toString().replaceAll("-","");
}
log.info("threadId"+Thread.currentThread().getId());
if(!(e instanceof OCmsExceptions)){
StringWriter sw=null;
PrintWriter pw=null;
try{
sw = new StringWriter();
pw = new PrintWriter(sw);
e.printStackTrace(pw);//将出错的栈信息输出到printWriter中
pw.flush();
sw.flush();
log.info("\n异常编码begin:"+ errorCode+"\n"+sw.toString().replaceAll("\\n","\n"+errorCode+":")+"\n异常编码end"+errorCode);
}
finally {
if(pw!=null){
pw.close();;
}
if(sw!=null){
pw.close();
}
}
}
return errorCode;
}
获取方式
@Service
public class Breadcrumb {
@Autowired(required = false)
private Tracer tracer;
public String getTracerId() {
if(tracer==null){
return "";
}
return tracer.getCurrentSpan().traceIdString();
}
public String getSpanId(){
if(tracer==null){
return "";
}
return String.valueOf(tracer.getCurrentSpan().getSpanId());
}
public String getParentId(){
if(tracer==null){
return "";
}
return tracer.getCurrentSpan().getParents()!=null?tracer.getCurrentSpan().getParents().toString():"";
}
}
注意 如果直接使用@AutowiredTracer 去拿会发现traceId跟当前链路不一致
使用log4j2配置
appender.info.layout.pattern = %d{yyyy-MM-dd HH:mm:ss z} [TraceId:%X{X-B3-TraceId},SpanId:%X{X-B3-SpanId},ParentSpanId:%X{X-B3-ParentSpanId},export:%X{X-Span-Export}] %-5level %class{36}%L %M - %msg%xEx%n
[TraceId:%X{X-B3-TraceId},SpanId:%X{X-B3-SpanId},ParentSpanId:%X{X-B3-ParentSpanId},export:%X{X-Span-Export}]