背景
我们自己基于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的接口的调用的整体的流程,所以到这里我们就知道了,就是在OnResonse
的ReturnEvent
的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
但是这个改动并不能解决刚才空指针的问题哦。
这里我们还要做一个修改就是,我们不在OnResponse
的 Return
方法去做返回值结果的获取,而是在 OnResponse
的 Before
的事件做处理即可。分析修改刚才有问题的 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);
}
增加如上的逻辑即可了。
如此即解决了流量录制的问题了。