jvm-sandbox-repeater http回放的“陷阱”与源码研读

使用任何一个新技术,必定要经过采坑的过程。一千个团队面临一万个场景,在不同的场景下审视同一个开源技术,一定会有不同的看法。我们基于开源,回馈开源,这才是开源的魅力。

repeater地址:https://github.com/alibaba/jvm-sandbox-repeater

本文所有源码分析基于commit id:0a1b47b2aae295a5c4627e533e7da94b9ed2b14d

我的场景

官方文档里介绍的slogan的例子,我在console里玩起来也是666,给组里测试的美眉也演示了一下,她跟我要了一个时间点:什么时候能用上?
于是基于sandbox做了一个docker基础镜像,美滋滋把一个业务服务部署起来,美滋滋录制、回放。但是在回放的时候,一直是失败的。

image.png

被回放的服务,报错日志如下:

Caused by: com.alibaba.jvm.sandbox.repeater.plugin.exception.RepeatException: no matching invocation found
    at com.alibaba.jvm.sandbox.repeater.plugin.core.impl.AbstractMockStrategy.execute(AbstractMockStrategy.java:69)
    at com.alibaba.jvm.sandbox.repeater.plugin.core.impl.AbstractInvocationProcessor.doMock(AbstractInvocationProcessor.java:75)
    at com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.doBefore(DefaultEventListener.java:156)
    at com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent(DefaultEventListener.java:118)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleEvent(EventListenerHandler.java:117)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353)
    at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164)
    at redis.clients.jedis.BinaryJedis.hgetAll(BinaryJedis.java)
    at org.springframework.data.redis.connection.jedis.JedisConnection.hGetAll(JedisConnection.java:2999)

从日志上看,是因为repeater的字节码增强导致了业务服务回放的时候报了500的错误。

问题探查

这个是为什么呢?repeater真的这么不健壮吗?去看一下报错的地方的代码:

if (select.isMatch() && invocation != null) {
    response = MockResponse.builder()
            .action(invocation.getThrowable() == null ? Action.RETURN_IMMEDIATELY : Action.THROWS_IMMEDIATELY)
            .throwable(invocation.getThrowable())
            .invocation(invocation)
            .build();
    mi.setSuccess(true);
    mi.setOriginUri(invocation.getIdentity().getUri());
    mi.setOriginArgs(invocation.getRequest());
} else {
    //就是这一行报的错
    response = MockResponse.builder()
            .action(Action.THROWS_IMMEDIATELY)
            .throwable(new RepeatException("no matching invocation found")).build();
}

这个地方的逻辑,解释起来可能会有点迷糊,因为不识庐山真面目,只缘身在此山中,各位先硬着头皮做一下局部理解,不需要发散。
上面这段代码隶属于AbstractMockStrategy, 这是一个通用的mock的策略实现。
这段代码围绕invocation来进行判断,invocation代表着回放时获取到的一个调用记录,可以是入口调用也可以是子调用,当然mock肯定是针对子调用进行的。
所以在这段代码执行之前,其实repeater已经根据回放id找到了之前录制的时候录制好的很多个子调用的记录。
举个例子,比如之前录制的时候,我调用业务的接口A,然后这个A的调用触发了很多次redis的操作,那么每一次redis的调用都是一次子调用,录制的时候会把每次与redis的交互的入参和返回接口都记录下来;
回放的时候呢,根据调用id可以找到很多的子调用记录,repeater会根据一个策略选择某一个字段用记录与当前回放阶段发生的子调用进行匹配:

//按照一定的策略匹配一次自调用记录
SelectResult select = select(request);
Invocation invocation = select.getInvocation();
//...
if (select.isMatch() && invocation != null) {
//找到了匹配的子调用,直接在回放的时候mock掉本次子调用
//...
} else {
//找不到对应的子调用,直接抛出异常
//...
}

基于上面的代码,repeater的逻辑其实很简单,回放的时候发生的子调用一定会存在于录制时,如果不存在,那一定是发生了意外情况,所以抛出异常。

疑点

按照常理来说,我的使用姿势没有特殊的,被录制的系统代码在回放的时候也没有发生变化,怎么会出现这种情况呢?难道是repeater有bug?不自觉的心中一喜。
(想要zheng解ming开ta这you个bug疑点,我几乎把repeater的核心源码都撸了一遍,然后才豁然开朗。)

问题原因解释

此处按照正向逻辑解释上面的疑点,但问题排查其实是一个逆向的过程,因为对源码不熟,还是花了很长时间的。

流量回时序图

基于源码研读,整理整个回放的时序图如下:


流量回放流程

流程解读

整体回放的时序图如上图,console这边通过页面触发回放之后,会向业务服务发起http调用,通过repeater的标准接口发起回放,注意此处请求并不是直接调用业务接口,而是调用repeater的此处贴一下脱敏后的回放抓包:

//request
POST /sandbox/default/module/http/repeater/repeat HTTP/1.1
Content-Type: application/x-www-form-urlencoded
Content-Length: 444
Host: *.*.*.*:12580
Connection: Keep-Alive
Accept-Encoding: gzip
User-Agent: okhttp/3.9.0

_data=xxxxxxxxxx

//RESPONSE:
HTTP/1.1 200 OK
Transfer-Encoding: chunked
Server: Jetty(8.y.z-SNAPSHOT)

submit success

核心流程一
这个请求的处理者是repeater,入口代码如下:

@Command("repeat")
public void repeat(final Map<String, String> req, final PrintWriter writer) {
    //...
}

上面这个函数类似spring mvc里的controller里的函数,它接到这个请求之后做了简单的处理之后就publish一个RepeatEvent,event处理的逻辑链路较长,此处贴一下整个调用链路:

com.alibaba.jvm.sandbox.repeater.plugin.core.impl.spi.RepeatSubscDefaultFlowDispatcherribeSupporter#onSubscribe
com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultFlowDispatcher#dispatch
com.alibaba.jvm.sandbox.repeater.plugin.core.impl.AbstractRepeater#repeat
com.alibaba.jvm.sandbox.repeater.plugin.core.impl.AbstractRepeater#sendRepeat
com.alibaba.jvm.sandbox.repeater.plugin.core.impl.AbstractBroadcaster#sendRepeat
com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultBroadcaster#broadcastRepeat
com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultBroadcaster#broadcast
com.alibaba.jvm.sandbox.repeater.plugin.core.util.HttpUtil#invokePostBody(java.lang.String, java.util.Map<java.lang.String,java.lang.String>, java.lang.String)
com.alibaba.jvm.sandbox.repeater.plugin.core.util.HttpUtil#invokePostBody(java.lang.String, java.util.Map<java.lang.String,java.lang.String>, java.util.Map<java.lang.String,java.lang.String[]>, java.lang.String)
com.alibaba.jvm.sandbox.repeater.plugin.core.util.HttpUtil#executeRequest(okhttp3.Request)  
com.alibaba.jvm.sandbox.repeater.plugin.core.util.HttpUtil#executeRequest(okhttp3.Request, int)  

感兴趣的,可以跟着源码看一下,上面这一坨的代码逻辑,其实是上面那张时序图里标注的核心流程一的内容。
核心流程一,要做的主要事情就是基于录制的记录,拼装回放请求,并向127.0.0.1发起回放的http请求, 此处其实发起的就是真正的业务请求了,如果console里没有开启mock开关,且业务系统接口不是幂等的,就可能会造成脏数据了,所以需要谨慎。

核心流程二
回放流量到了业务服务之后,业务代码和处理过程和标准业务处理是没什么两样的,关键就在于在执行某些子调用的时候,业务代码会被欺骗,被mock。
比如我的业务代码,原来计划是查询redis的,但是因为repeater识别到是回放流量,所以直接帮我把访问redis的操作给mock了,并根据录制的返回值把之前的返回结果再重新返回一遍。
这里的关键入口代码是:

//com.alibaba.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener
protected void doBefore(BeforeEvent event) throws ProcessControlException {
        // 回放流量;如果是入口则放弃;子调用则进行mock
        if (RepeatCache.isRepeatFlow(Tracer.getTraceId())) {
            processor.doMock(event, entrance, invokeType);
            return;
        }
        //...
    }

上面这段代码是一个事件监听器,这里的事件其实是sandbox一层发生的,repeater对事处理流程做了更高级一层的封装。对于before事件,如果识别到是流量回放过程,则直接进行mock。mock的逻辑如下代码:

//com.alibaba.jvm.sandbox.repeater.plugin.core.impl.AbstractInvocationProcessor
@Override
public void doMock(BeforeEvent event, Boolean entrance, InvokeType type) throws ProcessControlException {
    /*
     * 获取回放上下文
     */
    RepeatContext context = RepeatCache.getRepeatContext(Tracer.getTraceId());
    /*
     * mock执行条件
     */
    if (!skipMock(event, entrance, context) && context != null && context.getMeta().isMock()) {
        try {
            /*
             * 构建mock请求
             */
            final MockRequest request = MockRequest.builder()
                    .argumentArray(this.assembleRequest(event))
                    .event(event)
                    .identity(this.assembleIdentity(event))
                    .meta(context.getMeta())
                    .recordModel(context.getRecordModel())
                    .traceId(context.getTraceId())
                    .type(type)
                    .repeatId(context.getMeta().getRepeatId())
                    .index(SequenceGenerator.generate(context.getTraceId()))
                    .build();
            /*
             * 执行mock动作
             */
            final MockResponse mr = StrategyProvider.instance().provide(context.getMeta().getStrategyType()).execute(request);
            /*
             * 处理策略推荐结果
             */
            switch (mr.action) {
                case SKIP_IMMEDIATELY:
                    break;
                case THROWS_IMMEDIATELY:
                    ProcessControlException.throwThrowsImmediately(mr.throwable);
                    break;
                case RETURN_IMMEDIATELY:
                    ProcessControlException.throwReturnImmediately(assembleMockResponse(event, mr.invocation));
                    break;
                default:
                    ProcessControlException.throwThrowsImmediately(new RepeatException("invalid action"));
                    break;
            }
        } catch (ProcessControlException pce) {
            throw pce;
        } catch (Throwable throwable) {
            ProcessControlException.throwThrowsImmediately(new RepeatException("unexpected code snippet here.", throwable));
        }
    }
}

上面这段代码逻辑简单讲:
先提取录制的记录,然后封装成MockRequest, 然后基于特定的策略,匹配到具体的子调用并获取返回结果。然后基于返回结果对mock请求进行响应。

  • 提取录制记录:RepeatCache.getRepeatContext(Tracer.getTraceId());
  • 基于特定策略匹配特定自调用:StrategyProvider.instance().provide(context.getMeta().getStrategyType()).execute(request);
  • 进行返回值处理: switch (...) {...}

这里提取录制记录的地方,要想一下,这个缓存是什么时候放进去的呢?其实是在核心流程一里放置的。这块也是引发疑点的一个原因之一,后面解释。

这块的源码有一个地方需要解释一下,就是为什么要基于特定策略寻找匹配的子调用。

大家可以想一下,repeater下层是sandbox,sandbox简单来说,用来做代码增强的。再具体点讲,只能是在目标方法的前、后、抛异常等关键时刻插入一些额外的代码,并干扰原始方法的返回结果。

那么在录制的时候,其实repeater对子调用能记录的事情,其实是有限的,顶多是方法签名、入参等。一次调用,会包含多个子调用,一般是一个一对多的关系。然而在回放的时候呢,具体到某一个函数的执行,如果判断下来是在做回放,那么repeater就需要从多个子调用记录中找到和当前执行的子调用所匹配的一个,并根据录制的时候所录制的返回结果进行相同的结果返回。那么这个找到匹配的子调用的过程就是基于特定的策略的,目前开源的repeater里内置了几个策略:

image.png

这块,基于异常堆栈,我回放时报错的策略是ParameterMatchMockStrategy, 这是一个基于入参来进行子调用匹配的策略,简单讲就是如果当前子调用是一个redis的hgetall的请求,入参是a,那么如果在录制的子调用里能找到同样的redis的hgetall并且入参是a,则认为就是当前所匹配的子调用。源码如下:

@Override
protected SelectResult select(MockRequest request) {
    String parameter = Arrays.stream(request.getArgumentArray()).map(t -> new String((byte[]) t)).reduce((t1, t2) -> String.

    Stopwatch stopwatch = Stopwatch.createStarted();
    List<Invocation> subInvocations = request.getRecordModel().getSubInvocations();
    List<Invocation> target = Lists.newArrayList();

    
    // 第一步:根据方法签名过滤掉一批签名不同的方法
    
    // 第二步:根据方法入参,做相似度匹配,如果有匹配直接返回,并切从recordModel里删掉已匹配过的记录

    // 第三步: 如果没有找到,返回相似度最高的一条

}

上面就是核心流程二的简要说明。

谜团解密
上面核心流程一和二的解读,可能会比较晦涩,源码调用链路比较长,这里只能对大的链路进行描述,相当于是一个路标,具体的每一块的代码的阅读还是不能省略的。下面对谜团进行解释:

在问题排查的过程中,我进行了抓包,在我的回放过程中核心流程一总共发起了三次回放http请求而不是一次,并且这三次返回结果是不一样的,只有第一次是正常的,后面两次才是因为no matching invocation found的500错误。

所以有两个问题:
问题一:为什么发起多次请求?
这块的逻辑在核心流程一里:

//com.alibaba.jvm.sandbox.repeater.plugin.core.util.HttpUtil
public static Resp executeRequest(Request request) {
    return executeRequest(request, 3);
}

这块会进行三次的失败重试,但是我的请求并没有失败啊,为什么要重试?逻辑在这块:

//okhttp3.Response#isSuccessful
public boolean isSuccessful() {
    return this.code >= 200 && this.code < 300;
}

不是200,就认为是失败需要重试。
我录制回放的服务是一个鉴权服务,录制的case是鉴权失败的case,会返回401。当然我认为这种情况,不应该重试,bad case也是case,录制的时候401,回放也是401就证明case验证通过了。

问题二:为什么后面两次请求是no matching invocation found的500错误,而第一次不是?
还记得上面源码分析的地方提到过,根据ParameterMatchMockStrategy的策略,匹配过的子调用,会被删除,而基于问题一的解释,我的回放会被重试,所以...
调用记录只提取了一次,当第二次回放的时候,在提取的调用记录已经是第一次回放后修改过的记录信息了,即和当前回放匹配的子调用已经被删除了。
提取子调用的地方在com.alibaba.jvm.sandbox.repeater.plugin.core.impl.AbstractInvocationProcessor#doMock,上面的篇幅已经贴过源码了。

总结

我个人认为repeater这块设计的不太好:

  • 对于http请求不能非200就认为一定是失败的,业务我录制的就是非200的场景呢?
  • 关于这个context,属于典型的通过共享内存做数据通信的场景,对于这种全局变量, 声明周期管理尤其需要谨慎、清晰、简单;个人认为内存的设置和取用横跨两个流程,间隔太远了,虽然性能上做了一些权衡,但在清晰度上,我不认为这是一个好的设计。

我猜想阿里开源的repeater版本估计要滞后于他们内部的版本吧?总的来说,如果想把repeater应用到自己团队来使用,还有很多工作要做,最关键的一条,先把源码吃透,毕竟这是一个小众并且年轻的项目,经过验证的场景有限。如果不吃透其领域的概念,大概率只能玩一玩demo。
另外console目前看功能设计思路上还欠设计感,我仅说功能设计层面,比较单薄,当然官方文档貌似说后续会推出新的一版本的console。

如果我们团队使用repeater,我认为还有如下一些事情要做:

  • 配合基础镜像,开发sandbox中心化的管理平台,可以针对sandbox、sandbox module做版本管理,类似OTA升级
  • 不仅支持repeater的场景,还可以下发自定义module,这块想想空间比较大,比如快速修复安全漏洞,这块sandbox官方培训视频里鸾伽大佬也有提到过
  • 吃透源码
  • 可能需要开发一些repeater插件
  • 重新设计一下console的功能,最好能和公司内部的devops平台打通

sandbox是一个非常棒的生态,如果有余力,一定会在团队内部推动使用,相信一定能大大提升研发效率。

发散

其实复杂问题的解决方案,为了解决问题,可能会针对这个领域创造一些概念,比如购物领域,有商品、订单、支付、物流等概念,因为这些领域大众都比较熟悉,司空见惯了,所以不以为然了。
repeater本身是解决一个小众领域的解决方案,他自然要有一些他自己的核心概念,所以在理解这些概念之前去尝试分析问题,难免不识庐山真面目

最后

向sandbox团队致敬!向业界标杆致敬!

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 214,658评论 6 496
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,482评论 3 389
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 160,213评论 0 350
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,395评论 1 288
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,487评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,523评论 1 293
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,525评论 3 414
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,300评论 0 270
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,753评论 1 307
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,048评论 2 330
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,223评论 1 343
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,905评论 5 338
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,541评论 3 322
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,168评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,417评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,094评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,088评论 2 352