Spring Cloud Feign 記錄單個服務耗時并解決 Hystrix 執行緒隔離模式-有解無憂

隨著公司業務的增長，系統的呼叫量也越來越多，對于第三方支付平臺公司的我們，如何提高系統的穩定性是擺在我們面前的一個問題，為了解決系統穩定性問題，決定把整個服務的日志通過日志跟蹤號(traceNo) 以及一次呼叫鏈中每一個單個服務的呼叫時間列印到每個服務特定的目錄中，單個服務列印的資料運維會記錄到 ES 里面，提供大盤給各個業務系統 owner 優化服務，

分析這個需求，里面包含以下幾個需求：

決議上游傳遞過來的跟蹤號，添加到 MDC 中記錄整個日志，并且記錄在當前服務當中呼叫的整個耗時
把上游傳遞過來的跟蹤號傳遞到下游去，使得整個跟蹤號能夠串連起整個呼叫鏈
由于我們服務使用的是 Spring Cloud 所以可以使用 Spring 提供的 HandlerInterceptor 對呼叫進行增強，呼叫遠程服務使用的是 Feign ，可以使用 Feign 的擴展 RequestInterceptor 把 MDC 里面的日志跟蹤號通過 header 的形式傳遞給下游，

1、針對上游服務

針對上游服務我們使用 Spring 提供的 HandlerInterceptor 對呼叫進行增強，

1.1 Conventions

常量類，記錄當前需要使用到的一些常量資訊，

Conventions.java


public static class Conventions {


    /**
     * 遠程呼叫時用來傳遞統一背景關系UUID的HTTP HEADER
     */
    public static final String LOG_ID_HEADER         = "LOG_ID";

    /**
    * 在MDC中存放統一背景關系LOGID的KEY
    */
    public static final String CTX_LOG_ID_MDC        = "ctxLogId";

}

1.2 TraceEntity

資料模型類，保存當前服務資訊，跟蹤號呼叫路徑以及耗時，

TraceEntity.java


public class TraceEntity {

    /** 跟蹤號 */
    private String trackNo;

    /** 服務 ID */
    private String serviceId;

    /** http path */
    private String path;

    /** 呼叫耗時(ms) */
    private Long time;

}

1.3 WebDigestLogTimer

一次業務呼叫用時時間類，記錄服務呼叫的開始時間與結束時間，

WebDigestLogTimer.java

@Data
public class WebDigestLogTimer {
    /**
     * 開始處理時間
     */
    private Long beginTime;
    /**
     * 處理結束時間
     */
    private Long processEndTime;

}

1.4 ExecutionTimeHandlerInterceptor

通過繼承 Spring MVC 提供的 HandlerInterceptorAdapter 擴展類，在服務呼叫可以在服務呼叫的前后對服務進行增強，決議上游傳遞過來的 MDC 資訊以及服務資訊并且列印到服務指定的日志檔案當中，

ExecutionTimeHandlerInterceptor.java


public class ExecutionTimeHandlerInterceptor extends HandlerInterceptorAdapter {

    private final Logger logger;

    private final String serviceName;

    private ThreadLocal<WebDigestLogTimer> timer = new ThreadLocal<>();

    public ExecutionTimeHandlerInterceptor(String serviceName, String loggerName) {
        this.serviceName = serviceName;
        this.logger = LoggerFactory.getLogger(loggerName);
    }

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        addCtxLogId(request);

        WebDigestLogTimer logTimer = new WebDigestLogTimer();
        logTimer.setBeginTime(System.currentTimeMillis());
        timer.remove();
        timer.set(logTimer);
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
        timer.get().setProcessEndTime(System.currentTimeMillis());
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        WebDigestLogTimer logTimer = timer.get();
        Long costTime = logTimer.getProcessEndTime() - logTimer.getBeginTime();
        String path = request.getServletPath();
        String traceNo = MDC.get(Conventions.CTX_LOG_ID_MDC);
        TraceEntity traceEntity = TraceEntity.builder().trackNo(traceNo).serviceId(serviceName).path(path).time(costTime).build();
        logger.info("{} invoke {} cost time : {}, trace entity is {}", serviceName, path, costTime, JSON.toJSONString(traceEntity));
        MDC.clear();
    }

    private void addCtxLogId(HttpServletRequest request) {
        String ctxUniqId;
        if (StringUtils.isNotBlank(request.getHeader(Conventions.LOG_ID_HEADER))) {
            ctxUniqId = request.getHeader(Conventions.LOG_ID_HEADER);
        } else {
            ctxUniqId = UUID.randomUUID().toString();
        }
        MDC.put(Conventions.CTX_LOG_ID_MDC, ctxUniqId);
    }

}

2、針對于服務下游

對于服務下游來說就比較簡單，使用 Feign 的請求擴展 RequestInterceptor，可以把 MDC 里面的日志跟蹤號傳遞到請求的 header 里面，下游就可以使用上面的攔截器獲取到日志跟蹤號了，

LogIdRequestInterceptor

@Slf4j
public class LogIdRequestInterceptor implements RequestInterceptor {

    @Override
    public void apply(RequestTemplate template) {
        String ctxLogId = MDC.get(Conventions.CTX_LOG_ID_MDC);
        if(ctxLogId == null || ctxLogId.length() == 0) {
            log.warn("LogIdRequestInterceptor#apply get ctx log id is null");
            ctxLogId = UUID.randomUUID().toString();
        }
        template.header(Conventions.LOG_ID_HEADER, ctxLogId);
    }

}

但是這里有一個問題，在我們使用 Feign 進行遠程呼叫的時候，使用 Hystrix 進行執行緒隔離模式時，無法獲取ThreadLocal中資訊(MDC 基于 ThteadlLocal 實作)，我們的日志號就不能往下游傳遞了，其實 Hystrix 里面可以使用自定義并發策略解決這個問題，

3、自定義并 Hystrix 發策略解決

在這里我借鑒了一下 Discovery 里面對 Hystrix 的擴展，

3.1 StrategyCallableWrapper

自定義執行緒包裝介面，擴展 Hystrix 執行緒創建策略，

StrategyCallableWrapper.java


public interface StrategyCallableWrapper {

    <T> Callable<T> wrapCallable(Callable<T> callable);

}

3.2 DefaultStrategyCallableWrapper

默認的實作類，把 MDC 里面保存的日志 ID，傳遞到子執行緒里面去，

DefaultStrategyCallableWrapper.java


public class DefaultStrategyCallableWrapper implements StrategyCallableWrapper {

    @Override
    public <T> Callable<T> wrapCallable(Callable<T> callable) {
        String ctxLogId = MDC.get(Conventions.CTX_LOG_ID_MDC);
        return () -> {
            try {
                MDC.put(Conventions.CTX_LOG_ID_MDC, ctxLogId);
                return callable.call();
            } finally {
                MDC.clear();
            }
        };
    }

}

3.3 HystrixContextConcurrencyStrategy

HystrixContextConcurrencyStrategy繼承 HystrixConcurrencyStrategy自定義并發策略, 解決使用 Hystrix 執行緒隔離模式時，無法獲取ThreadLocal中資訊，

HystrixContextConcurrencyStrategy.java


public class HystrixContextConcurrencyStrategy extends HystrixConcurrencyStrategy {

    @Autowired
    private StrategyCallableWrapper strategyCallableWrapper;

    private HystrixConcurrencyStrategy hystrixConcurrencyStrategy;

    public HystrixContextConcurrencyStrategy() {
        // HystrixPlugins只能注冊一次策略，保留原物件
        this.hystrixConcurrencyStrategy = HystrixPlugins.getInstance().getConcurrencyStrategy();

        // Keeps references of existing Hystrix plugins.
        HystrixCommandExecutionHook commandExecutionHook = HystrixPlugins.getInstance().getCommandExecutionHook();
        HystrixEventNotifier eventNotifier = HystrixPlugins.getInstance().getEventNotifier();
        HystrixMetricsPublisher metricsPublisher = HystrixPlugins.getInstance().getMetricsPublisher();
        HystrixPropertiesStrategy propertiesStrategy = HystrixPlugins.getInstance().getPropertiesStrategy();

        HystrixPlugins.reset();

        // Registers existing plugins excepts the Concurrent Strategy plugin.
        HystrixPlugins.getInstance().registerConcurrencyStrategy(this);
        HystrixPlugins.getInstance().registerCommandExecutionHook(commandExecutionHook);
        HystrixPlugins.getInstance().registerEventNotifier(eventNotifier);
        HystrixPlugins.getInstance().registerMetricsPublisher(metricsPublisher);
        HystrixPlugins.getInstance().registerPropertiesStrategy(propertiesStrategy);
    }

    @Override
    public BlockingQueue<Runnable> getBlockingQueue(int maxQueueSize) {
        return hystrixConcurrencyStrategy.getBlockingQueue(maxQueueSize);
    }

    @Override
    public <T> HystrixRequestVariable<T> getRequestVariable(HystrixRequestVariableLifecycle<T> rv) {
        return hystrixConcurrencyStrategy.getRequestVariable(rv);
    }

    @Override
    public ThreadPoolExecutor getThreadPool(HystrixThreadPoolKey threadPoolKey, HystrixProperty<Integer> corePoolSize, HystrixProperty<Integer> maximumPoolSize, HystrixProperty<Integer> keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
        return hystrixConcurrencyStrategy.getThreadPool(threadPoolKey, corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }

    @Override
    public ThreadPoolExecutor getThreadPool(HystrixThreadPoolKey threadPoolKey, HystrixThreadPoolProperties threadPoolProperties) {
        return hystrixConcurrencyStrategy.getThreadPool(threadPoolKey, threadPoolProperties);
    }

    @Override
    public <T> Callable<T> wrapCallable(Callable<T> callable) {
        return strategyCallableWrapper.wrapCallable(callable);
    }

}

3.4 方便使用方接入

并且為了方便使用方接入，在這里使用 Spring Boot 的自動依賴配置功能，

HystrixStrategyAutoConfiguration.java

@Configuration
@ConditionalOnClass(Hystrix.class)
@ConditionalOnProperty(value = "logger.strategy.hystrix.threadlocal.supported", matchIfMissing = false)
public class HystrixStrategyAutoConfiguration {

    @Bean
    public HystrixContextConcurrencyStrategy hystrixContextConcurrencyStrategy() {
        return new HystrixContextConcurrencyStrategy();
    }

    @Bean
    public DefaultStrategyCallableWrapper strategyCallableWrapper(){
        return new DefaultStrategyCallableWrapper();
    }

}

在專案的資源目錄添加以下檔案：


+ resources
  └ META-INF
    └ spring.factories

org.springframework.boot.autoconfigure.EnableAutoConfiguration=\
com.ushareit.fintech.framework.log.trace.HystrixStrategyAutoConfiguration

使用方只有在 classpath 里面引入了 Hystrix 的 jar 包并且在組態檔中添加logger.strategy.hystrix.threadlocal.supported=true的時候才會激活 Hystrix 日志引數傳遞，

4、使用方如何接入

下面來看一下使用方是如何絲滑的接入這個功能的，

4.1 引入 Jar 包

需要使用這個功能，當然需要使用里面的類，所以我們需要依賴提供這些類的 Jar 包

<dependency>
    <groupId>com.xxx.xxx.framework</groupId>
    <artifactId>common-log</artifactId>
    <version>1.0.2</version>
</dependency>

4.2 組態檔(針對 Hystrix 專案)

需要在 spring boot 專案中的 application.properties 檔案中添加以下配置：

logger.strategy.hystrix.threadlocal.supported=true

注意：如果你的專案中并沒有使用 Hystrix，請忽略當前步驟，

4.3 上游服務 Header 處理

構建器里面添加 test-server 服務名稱，以及需要列印日志的 logger 名稱，然后通過 Spring 里面提供的 @Configuration 和 @EnableWebMvc 激活，

WebMvcConfig .java

@Configuration
@EnableWebMvc
public class WebMvcConfig extends WebMvcConfigurerAdapter{

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        // MDC
        ExecutionTimeHandlerInterceptor executionTimeInterceptor = new ExecutionTimeHandlerInterceptor("test-service", "WEB-DIGEST-LOGGER");
        registry.addInterceptor(executionTimeInterceptor);
    }

}

4.4 傳遞 Header 到下游服務

配置 LogIdRequestInterceptor 物件，把它添加到 Spring 容器里面，并且配置到 Feign 呼叫服務的配置類里面:

FeignConfiguration.java

##  1 FeignConfiguration

@Configuration
public class FeignConfiguration {

    @Bean
    public LogIdRequestInterceptor logIdRequestInterceptor(){
        return new LogIdRequestInterceptor();
    }

}

### 2 啟動類上面添加注解
@EnableFeignClients(basePackages = { "com.xxxx.xxxx.payment.integration.service" }, defaultConfiguration = {FeignConfiguration.class})

4.5 日志配置

由于專案中使用的日志框架是 log4j2 ，所以要在 classpath:log4j2.xml 里面配置成以下資訊，

<?xml version="1.0" encoding="UTF-8"?>

<!-- 設定log4j2的自身log級別為error -->
<configuration status="error">
    <Properties>
        <Property name="dir">logs</Property>
        <Property name="logFormat">[%d{yyyy-MM-dd HH:mm:ss}] [%-5level] [%t] [%X{ctxLogId}] [pay-fintech-service] [%c(%L)] %m%n
        </Property>
        <Property name="every_file_size">100MB</Property>
        <Property name="log_level">info</Property>
        <Property name="myAdditivity">false</Property>
    </Properties>

   <appenders>

       <RollingFile name="WEB-DIGEST" fileName="${dir}/web-digest.log" filePattern="${dir}/web-digest-%d{yyyy-MM-dd}-%i.log">
           <ThresholdFilter level="INFO"/>
           <PatternLayout pattern="${logFormat}"/>
           <Policies>
           <TimeBasedTriggeringPolicy/>
           <SizeBasedTriggeringPolicy size="${every_file_size}"/>
           </Policies>
       </RollingFile>
   </appenders>

   <loggers>
      <logger name="WEB-DIGEST-LOGGER" level="info" additivity="${myAdditivity}">
          <appender-ref ref="WEB-DIGEST" />
          <appender-ref ref="ERROR" />
   </logger>
   <root level="${log_level}">
      <appender-ref ref="SERVICE" />
      <appender-ref ref="CONSOLE" />
      <appender-ref ref="ERROR"  />
   </root>
   </loggers>
</configuration>

大家需要添加的內部片段如下：

日志列印地址：

       <RollingFile name="WEB-DIGEST" fileName="${dir}/web-digest.log" filePattern="${dir}/web-digest-%d{yyyy-MM-dd}-%i.log">
           <ThresholdFilter level="INFO"/>
           <PatternLayout pattern="${logFormat}"/>
           <Policies>
           <TimeBasedTriggeringPolicy/>
           <SizeBasedTriggeringPolicy size="${every_file_size}"/>
           </Policies>
       </RollingFile>

日志名稱(也就是 ExecutionTimeHandlerInterceptor 里面配置的日志名稱)

   <loggers>
      <logger name="WEB-DIGEST-LOGGER" level="info" additivity="false">
          <appender-ref ref="WEB-DIGEST" />
          <appender-ref ref="ERROR" />
   </logger>

是不是很順滑？

轉載請註明出處，本文鏈接：https://www.uj5u.com/houduan/230713.html

標籤：java

上一篇：cookie實作頁面顯示上次訪問時間

下一篇：用IDEA 來寫第一個Springboot程式以及歡樂的避坑指南