dubbo流量录制异常(dubbo2.7.3)的问题解决排查

背景

我们自己基于jvm-sandbox-repeater做的流量录制出现了如下的问题, 从这个问题的堆栈信息来看,是在针对dubbo的调用的时候判断这个dubbo的返回是否有异常的时候,报了空指针异常了。
在这里插入图片描述

分析

我们看下具体出错的代码地方是怎么样的吧。

@Override
   protected void doReturn(ReturnEvent event) {
       if (RepeatCache.isRepeatFlow(Tracer.getTraceId())) {
           return;
       }
       Invocation invocation = RecordCache.getInvocation(event.invokeId);
       if (invocation == null) {
           log.debug("no valid invocation found in return,type={},traceId={}", invokeType, Tracer.getTraceId());
           return;
       }
       Boolean hasException = ((DubboConsumerInvocationProcessor)processor).isHasException(event);
       if (hasException) {
           invocation.setThrowable((Throwable) processor.assembleResponse(event));

           invocation.setResponse(buildExceptionResponse(invocation.getThrowable()));

       }   else {

       }
       invocation.setResponse(processor.assembleResponse(event));
       invocation.setEnd(System.currentTimeMillis());
       listener.onInvocation(invocation);
   }
/**
     * 判断是否有异常
     * @param event
     * @return
     */
    public Boolean isHasException(Event event) {
        if (event.type == Event.Type.RETURN) {
            Object appResponse = ((ReturnEvent) event).object;
            try {
                return (Boolean) MethodUtils.invokeMethod(appResponse, "hasException");
            } catch (Exception e) {
                // ignore
                LogUtil.error("error occurred when assemble dubbo response", e);
            }
        }
        return false;

    }

从上面的代码可以看出来,出错的地方是event的object为null的情况导致了这个问题。

但是这个地方怎么会出现null的,没有思路,所以我们这里借助arthas进行分析下, 我们就 watch这个 isHasException 看看这个 event 的内容是什么

watch com.alibaba.jvm.sandbox.repeater.plugin.dubbo.DubboConsumerInvocationProcessor isHasException '{params,returnObj,throwExp}'  -n 5  -x 3
method=com.alibaba.jvm.sandbox.repeater.plugin.dubbo.DubboConsumerInvocationProcessor.isHasException location=AtExit
ts=2023-06-10 16:12:50; [cost=3.393034ms] result=@ArrayList[
    @Object[][
        @ReturnEvent[
            object=null,
            processId=@Integer[8969],
            invokeId=@Integer[8969],
            type=@Type[RETURN],
        ],
    ],
    @Boolean[false],
    null,
]

从上述的代码,确实可以看到,object的结果为null, 所以这确实就会导致空指针的异常,可是问题还是没有太好的思路,因为针对ReturnEvent 这个类中的信息太少了,没有太多能够分析的,所以最好的方式还是去看 入口的 onEvent 的方法,这里是所有事件进来的入口,这样子才能更好的分析问题

[arthas@75]$ watch com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener onEvent '{params,returnObj,throwExp}'  -n 50  -x 3 
Press Q or Ctrl+C to abort.
Affect(class count: 6 , method count: 1) cost in 853 ms, listenerId: 7
method=com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent location=AtExit
ts=2023-06-10 16:26:18; [cost=7.911702ms] result=@ArrayList[
    @Object[][
        @BeforeEvent[
            javaClassLoader=@LaunchedURLClassLoader[org.springframework.boot.loader.LaunchedURLClassLoader@8688f78],
            javaClassName=@String[org.apache.dubbo.rpc.filter.ContextFilter],
            javaMethodName=@String[invoke],
            javaMethodDesc=@String[(Lorg/apache/dubbo/rpc/Invoker;Lorg/apache/dubbo/rpc/Invocation;)Lorg/apache/dubbo/rpc/Result;],
            target=@ContextFilter[org.apache.dubbo.rpc.filter.ContextFilter@352eba13],
            argumentArray=@Object[][isEmpty=false;size=2],
            processId=@Integer[15730],
            invokeId=@Integer[15730],
            type=@Type[BEFORE],
        ],
    ],
    null,
    null,
]
...
...
method=com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent location=AtExit
ts=2023-06-10 16:26:18; [cost=3.775966ms] result=@ArrayList[
    @Object[][
        @ReturnEvent[
            object=@AsyncRpcResult[org.apache.dubbo.rpc.AsyncRpcResult@516b9850[Completed normally]],
            processId=@Integer[15730],
            invokeId=@Integer[15730],
            type=@Type[RETURN],
        ],
    ],
    null,
    null,
]
method=com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent location=AtExit
ts=2023-06-10 16:26:18; [cost=0.141919ms] result=@ArrayList[
    @Object[][
        @BeforeEvent[
            javaClassLoader=@LaunchedURLClassLoader[org.springframework.boot.loader.LaunchedURLClassLoader@8688f78],
            javaClassName=@String[org.apache.dubbo.rpc.filter.ContextFilter$ContextListener],
            javaMethodName=@String[onResponse],
            javaMethodDesc=@String[(Lorg/apache/dubbo/rpc/Result;Lorg/apache/dubbo/rpc/Invoker;Lorg/apache/dubbo/rpc/Invocation;)V],
            target=@ContextListener[org.apache.dubbo.rpc.filter.ContextFilter$ContextListener@1a077c5e],
            argumentArray=@Object[][isEmpty=false;size=3],
            processId=@Integer[15733],
            invokeId=@Integer[15733],
            type=@Type[BEFORE],
        ],
    ],
    null,
    null,
]
method=com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent location=AtExit
ts=2023-06-10 16:26:18; [cost=1.434189ms] result=@ArrayList[
    @Object[][
        @ReturnEvent[
            object=null,
            processId=@Integer[15733],
            invokeId=@Integer[15733],
            type=@Type[RETURN],
        ],
    ],
    null,
    null,
]

这里我把中间的链路简化了一些,从这里我们就可以看到一个大概的流程情况了,

Before(Invoke) → Return(Invoke) → Before(OnResponse)→ Return(OnResponse)

这个链路其实都是一个dubbo的接口的调用的整体的流程,所以到这里我们就知道了,就是在OnResonseReturnEvent 的object 为null 导致了这个问题了,这个流程其实就有问题 因为 我们既然已经在invoke 那里监听了return事件的话,那 onResponse 的return, 其实也没有意义。

DubboProviderPlugin.java

@Override
protected List<EnhanceModel> getEnhanceModels() {
    EnhanceModel onResponse = EnhanceModel.builder().classPattern("org.apache.dubbo.rpc.filter.ContextFilter$ContextListener")
            .methodPatterns(EnhanceModel.MethodPattern.transform("onResponse"))
            .watchTypes(Event.Type.BEFORE, Event.Type.RETURN, Event.Type.THROWS)
            .build();
    EnhanceModel invoke = EnhanceModel.builder().classPattern("org.apache.dubbo.rpc.filter.ContextFilter")
            .methodPatterns(EnhanceModel.MethodPattern.transform("invoke"))
            .watchTypes(Event.Type.BEFORE, Event.Type.RETURN, Event.Type.THROWS)
            .build();
    return Lists.newArrayList(invoke, onResponse);
}

所以这里的好的方式是去掉 invoke中的 Event.Type.Return 但是这个改动并不能解决刚才空指针的问题哦。

这里我们还要做一个修改就是,我们不在OnResponseReturn 方法去做返回值结果的获取,而是在 OnResponseBefore 的事件做处理即可。分析修改刚才有问题的 isHasException 以及

assembleResponse 如下:

public Boolean isHasException(Event event) {
    if (event.type == Event.Type.BEFORE && ON_RESPONSE.equals(((BeforeEvent)event).javaMethodName)) {
        Object appResponse = ((BeforeEvent) event).argumentArray[0];
        try {
            return (Boolean) MethodUtils.invokeMethod(appResponse, "hasException");
        } catch (Exception e) {
            // ignore
            LogUtil.error("error occurred when assemble dubbo response", e);
        }
    }
    return false;
}

@Override
public Object assembleResponse(Event event) {

    if (event.type == Event.Type.BEFORE && ON_RESPONSE.equals(((BeforeEvent)event).javaMethodName)) {
        Object appResponse = ((BeforeEvent) event).argumentArray[0];
        try {
            Object result =  MethodUtils.invokeMethod(appResponse, "getValue");
            if (result == null) {
                return MethodUtils.invokeMethod(appResponse, "getException");
            }else {
                return result;
            }
        } catch (Exception e) {
            // ignore
            LogUtil.error("error occurred when assemble dubbo response", e);
        }
    }
    return null;
}

全部都切换成在Before的时候做数据的获取即可了。

再思考

这个问题这么修改就可以了吗,不一定,尤其呢这个改动其实挺大的,尤其我们在代码增强的时候还去掉了 invoke的 return的增强。

另外其实还有一个比较重要的事情,这里忽略掉了,这个问题出现之前其实我们的流量录制在其他项目也跑过,dubbo 接口的录制其实是没有问题的,但是在这个项目上运行就不听的报错。这个就是非常奇怪的问题了,而出现这个问题能想到的原因很大概率都是dubbo版本的情况了,检查后确实发现dubbo版本存在有差异,我们没问题的版本是2.7.18, 但是有问题的dubbo版本是2.7.3。 这两个dubbo版本的差异在哪呢。

所以我们重点需要看下 我们前面一开始做的代码增强的类。也就是 org.apache.dubbo.rpc.filter.ContextFilter

以下是2.7.18版本的, 以下的代码都去掉了一下不重要的部分内容

package org.apache.dubbo.rpc.filter;

/**
 * ContextFilter set the provider RpcContext with invoker, invocation, local port it is using and host for
 * current execution thread.
 *
 * @see RpcContext
 */
@Activate(group = PROVIDER, order = Integer.MIN_VALUE)
public class ContextFilter implements Filter, Filter.Listener {
    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
       ...
    }

    @Override
    public void onResponse(Result appResponse, Invoker<?> invoker, Invocation invocation) {
        // pass attachments to result
        appResponse.addObjectAttachments(RpcContext.getServerContext().getObjectAttachments());
    }

    @Override
    public void onError(Throwable t, Invoker<?> invoker, Invocation invocation) {

    }
}

以下是2.7.3 版本的

package org.apache.dubbo.rpc.filter;

@Activate(
    group = {"provider"},
    order = -10000
)
public class ContextFilter extends ListenableFilter {
    private static final String TAG_KEY = "dubbo.tag";

    public ContextFilter() {
        super.listener = new ContextListener();
    }

    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        ...
    }

    static class ContextListener implements Filter.Listener {
        ContextListener() {
        }

        public void onResponse(Result appResponse, Invoker<?> invoker, Invocation invocation) {
            appResponse.addAttachments(RpcContext.getServerContext().getAttachments());
        }

        public void onError(Throwable t, Invoker<?> invoker, Invocation invocation) {
        }
    }
}

对比这两个类,我们就明显发现了区别的地方。在2.7.3的版本,onResponse是在 ContextFilter 下,但是在2.7.18的版本 onResponse却是在 ContextFilter的内部类ContextListener 中,所以这个我们就知道为什么了,因为我们的代码增强的逻辑里面 并没有增强ContextFilter 类下的onResponse.

所以回过来,我们刚才的修改就明显有问题了,这样子的修改就会导致2.7.3版本的dubbo录制没有返回值录制到的情况,所以我们还需要再做一点修改。也就是如下:

@Override
    protected List<EnhanceModel> getEnhanceModels() {
        EnhanceModel onResponse = EnhanceModel.builder().classPattern("org.apache.dubbo.rpc.filter.ContextFilter")
                .methodPatterns(EnhanceModel.MethodPattern.transform("onResponse"))
                .watchTypes(Event.Type.BEFORE, Event.Type.RETURN, Event.Type.THROWS).build();

        // 兼容dubbo 2.7.3版本
        EnhanceModel onResponseV2 = EnhanceModel.builder().classPattern("org.apache.dubbo.rpc.filter.ContextFilter$ContextListener")
                .methodPatterns(EnhanceModel.MethodPattern.transform("onResponse"))
                .watchTypes(Event.Type.BEFORE, Event.Type.RETURN, Event.Type.THROWS).build();

        EnhanceModel invoke = EnhanceModel.builder().classPattern("org.apache.dubbo.rpc.filter.ContextFilter")
                .methodPatterns(EnhanceModel.MethodPattern.transform("invoke"))
                .watchTypes(Event.Type.BEFORE, Event.Type.THROWS).build();
        return Lists.newArrayList(invoke, onResponse, onResponseV2);
    }

增加如上的逻辑即可了。

如此即解决了流量录制的问题了。

  • 0
    点赞
  • 1
    收藏
    觉得还不错? 一键收藏
  • 1
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论 1
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值