作用
再微服務中 服務調用服務很常見。服務中相互調用鏈路追蹤的尤為重要,能夠幫助我們再異常時分析出哪個服務出了異常。以及各個鏈路中相互調用所消耗時間,通過這些數據能夠幫助我們分析出各個服務的性能瓶頸
簡單例子
在之前的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}]