微服务调用链的排查,请求日志排查超时时间,锁定超时的原因

微服务调用链的排查,请求日志排查超时时间,锁定超时的原因

A微服务 >> B微服务 >> C微服务 论日志的请求开始时间和结束时间的重要性。

完整的日志格式：另外接口的入参，出参也需要加上，日志需要根据参数的关键字来搜索，比如会员号，ID等唯一标识。
A服务
logger.info("调用B服务httpParams=" + GsonUtils.toJson(httpParams));
调用B服务
logger.info("调用B服务httpResult=" + GsonUtils.toJson(httpResult));

B服务
logger.info("调用C服务httpParams=" + GsonUtils.toJson(httpParams));
调用C服务
logger.info("调用C服务httpResult=" + GsonUtils.toJson(httpResult));

C服务
logger.info("调用外部接口httpParams=" + GsonUtils.toJson(httpParams));
调用外部第三方接口
logger.info("调用外部接口httpResult=" + GsonUtils.toJson(httpResult));

如果调用链微服务没有httpParams这一条日志（日志没有成对出现），否则日志只能是倒排查询,倒序来推测请求是什么时间开始的。

外部接口请求超时时间设置20秒超时，调用方超时时间5秒修改成10秒，方案是：外部接口超时时间调整为8秒，在调用方的10秒内。不影响主流业务。

外部接口调用异常 捕捉异常，外部服务内部消化，或记录需要人工介入处理，
对外部调用方接口正常返回，“success”，对外部的调用没有影响。不影响主流程的业务进行。否则主流程会因为外部接口的超时而报“系统错误”。

linux排查日志截取：
sed -n '/2023-12-07 12:56:14.442/,/2023-12-07 12:56:43.710/p' test-2023-12-07-44.log >> test-231207.log

 

1.调用外部接口的日志输出格式：请求的入参，出参，请求消耗时间。
开始时间：1701924983639
结束时间：1701924994491
消耗时间：20033
请求返回：null

参考code(排查接口的请求响应时间):

    long startTime = System.currentTimeMillis();
    log.info("开始时间：" + startTime);

    long endTime = System.currentTimeMillis();
    log.info("结束时间：" + endTime);

    log.info("消耗时间：" + (endTime - startTime));

重点：需要排查接口里面的是否调用了延时

Thread.sleep(3000);

等方法，否则需要采用同步改异步的方式来调用。 @Async，不影响主流程的进行和占用主流程的接口耗时。

//springboot增加@EnableAsync注解，否则方法中的@Async注解没有生效。 注意点

@EnableFeignClients(basePackages = {"com.test", "com.test.order"})
@EnableAsync
@EnableEurekaClient
@SpringBootApplication
public class MyApplication extends SpringBootServletInitializer {

}

 

2.调用外部服务的请求日志表，请求参数入库，返回结果入库，方便排查时候查询请求log。锁定时间

GsonUtils.java
private static final Gson gson = new GsonBuilder().setDateFormat("yyyy-MM-dd HH:mm:ss").create();

public static String toJson(Object obj) {
    if (obj == null) {
        return "";
    }
    return gson.toJson(obj);
}