背景:刚接手一个新工程,是一个给国内top级医院开发的老项目,因为历史原因,代码质量略低,测试难度略高。
上线很久的功能,最近一直频繁的爆发各种问题,经排查发现都是因为在业务过程中im聊天账号绑定异常所致。
修复方案一:
因为im工程比较老,日志打印不完善,因此从日志看初步分析业务dubbo接口未调用到im服务因此导致了绑定失败,此时我开始在工程里设置dubbo接口该方法的重试机制,retries设置为2,timeout设置为3000,由于本身既有的一次rpc调用,因此实际在调用失败的情况下业务会对im接口进行3次rpc的调用。
鉴于项目的各种难度和稳定性要求,另在业务代码侧再次进行了三次递归重试(客户端超时30s,正常情况不会因为重试而超时,慢是肯定的)。
同时因为服务此时并没有打印traceId进行链路跟踪机制的拓展,因此另开发traceId写入MDC并通过log4j2打印到cosole并通过钉钉表达式进行采集汇总输出,针对dubbo接口也通过扩展spi进行了traceId的透传。
服务消费者端代码如下:
import org.apache.commons.lang3.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.core.Ordered;
import org.springframework.core.annotation.Order;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import javax.servlet.FilterChain;
import javax.servlet.annotation.WebFilter;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
/**
* MDC属性设置 日志用
* 方法屏蔽actuator接口
*/
@Order(Ordered.HIGHEST_PRECEDENCE)
@WebFilter(urlPatterns = {"/*"})
public class MDCFilter extends OncePerRequestFilter {
private Logger LOGGER = LoggerFactory.getLogger(MDCFilter.class);
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain) {
if(request.getRequestURI().contains("/actuator/health")){
return;
}
try {
String traceId = request.getHeader("traceId");
if(StringUtils.isNotBlank(traceId)) {
TraceIdUtil.create(traceId);
} else {
TraceIdUtil.create();
}
TraceContext.addAttachment("traceId",MDC.get("traceId"));
chain.doFilter(new ContentCachingRequestWrapper(request), response);
} catch (Exception exception) {
LOGGER.error("Web端traceId处理异常", exception);
} finally {
TraceContext.clear();
TraceIdUtil.clear();
}
}
}
import java.util.UUID;
import org.slf4j.MDC;
public class TraceIdUtil {
public static final String TRACE_ID = "traceId";
public TraceIdUtil() {
}
public static void create() {
create(UUID.randomUUID().toString().replace("-", ""));
}
public static void create(String traceId) {
MDC.put("traceId", traceId);
}
public static String get() {
return MDC.get("traceId");
}
public static void clear() {
MDC.clear();
}
}
import com.alibaba.dubbo.common.extension.Activate;
import com.alibaba.dubbo.rpc.*;
@Activate(group = {"consumer"})
public class DubboTraceFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
RpcContext rpcContext = RpcContext.getContext();
if (rpcContext.isConsumerSide()) {
rpcContext.setAttachment("traceId", TraceContext.getTraceId());
}
return invoker.invoke(invocation);
}
}
public class TraceContext {
private static ThreadLocal<Map<String,Object>> threadLocal = new ThreadLocal<Map<String, Object>>(){
@Override
protected Map<String, Object> initialValue() {
return new LinkedHashMap<String, Object>();
}
};
public static void addAttachment(String key, Object value){
threadLocal.get().put(key,value);
}
public static void addAttachments(Map<String, Object> map){
threadLocal.get().putAll(map);
}
public static Map<String, Object> getAttachments(){
return threadLocal.get();
}
public static void clear(){
threadLocal.remove();
}
public static String getTraceId(){
return String.valueOf(threadLocal.get().get("traceId"));
}
}
启动类添加注解:@ServletComponentScan
resource目录新建文件com.alibaba.dubbo.rpc.Filter
文件内容
dubboTraceFilter=com.xxx.filter.DubboTraceFilter(文件路径)
文件结构如下
服务提供者端代码如下:
import com.alibaba.dubbo.common.extension.Activate;
import com.alibaba.dubbo.rpc.*;
import org.apache.commons.lang.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
@Activate(group = {"provider","consumer"})
public class TraceIdFilter implements Filter {
private static final Logger LOGGER = LoggerFactory.getLogger(TraceIdFilter.class);
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
try{
String traceId = RpcContext.getContext().getAttachment("traceId");
if ( !StringUtils.isEmpty(traceId) ) {
// *) 从RpcContext里获取traceId并保存
MDC.put("traceId", traceId);
} else {
// *) 交互前重新设置traceId, 避免信息丢失
TraceIdUtil.create();
RpcContext.getContext().setAttachment("traceId", MDC.get("traceId"));
}
// *) 实际的rpc调用
return invoker.invoke(invocation);
}catch (Exception e){
LOGGER.error("rpcContext get traceId exception:",e);
return null;
}finally {
TraceIdUtil.clear();
}
}
}
提供者端SPI扩展相同
此外:1、Log4j2需要解析自定义的traceId标签,可以用%X{traceId}打印
2、resources目录下文件路径注意com.alibaba还是apache dubbo,请与依赖保持一致
至此,问题修复完成。
代码上线后,发现问题依然存在。(上述方案仅可在一定程度上避免,并不能完全修复)
修复方案二:
再次排查发现,原来是im接口有另一个实现也在提供服务,此时找到了问题的元凶,摘除该无用实现问题解决。(也可考虑group隔离,因为另一实现无用,因此摘除)
经验总结:im的另一实现是前几天上线一新功能随之发布的,因为dubbo接口默认路由的随机性及测试账号的历史原因,导致该问题在测试过程未被发现。实际上当我们上线任何新功能,都应该全面进行评估上线代码是否会对老功能造成影响,而不应该只局限在眼前的需求,从而造成更大的损失。