一次zuul版本升级产生的问题排查记录

起因

事情的起因是由于早期的一些服务版本放到现在太低了,基本上都是SpringBoot1.5.x,因此准备统一对服务进行一次版本升级,升级到2.1.xSpringCloud``版本升级到Greenwich。当然我们用的旧版本的zuul相关的都需要升级。

意外的Bug

我们网关使用的是zuul,使用的是spring-cloud-netflix封装的包,此次版本升级同步升级了相关的包。但是意外的情况发生了,在测试环境上我们发现上传文件会出现异常。具体表现是这样的:当上传的文件超出一定大小后,在经过zuul网关并向其他服务转发的时候,之前上传的包就不见了。这个情况十分奇怪,因此马上开始排查。

Bug的排查

出现这样的问题,第一反应是测试是不是根本没有上传包所以当然包没法转发到下一层,当然这种想法很快被否定了。好吧,那就认真的排查吧。

首先先去追踪了一下路由以及出现的具体日志,将问题定位到zuul服务,排除了上游nginx和下游业务服务出现问题的可能。但是zuul服务没有任何异常日志出现,所以非常困扰。检查过后发现文件确实有通过zuul,但是之后凭空消失没有留下一点痕迹。

明明当初考虑上传文件的问题给zuul分配了两个g的内存,怎么上传500m的文件就出问题了呢?不对!此时我灵光一闪,会不会和垃圾回收机制有关。我们的文件是非常大的,这样的大文件生成的大对象是会保存在java的堆上的,并且由于垃圾回收的机制,这样的对象不会经历年轻代,会直接分配到老年代,会不会是由于我们内存参数设置不合理导致老年代太小而放不下呢?想到做到,我们通过调整jvm参数,保证了老年代至少有一个G的空间,并且同步检测了java的堆内存的状态。然而让人失望的是居然没有奏效。不过此时事情和开始不同,我们有了线索。在刚才的堆的内存监控中发现了一些异常,随即合理怀疑是堆中内存不够导致了oom。随后加大内存尝试并且再次运行,发现居然上传成功了。果然是老年代内存不足导致的oom,不过虽然上传成功,但是老年代中的内存居然被占用了1.6G左右,明明是500M的文件,为什么会占用了这么大的内存呢?

虽然找到了原因,但是增加内存显然不是解决问题的方法,因此,我们在启动参数上新增了-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data准备查看oom的具体分析日志。

OOM信息

查看堆栈信息可以发现,溢出是发生在byte数组的拷贝上,我们迅速定位代码,可以找到如下的代码:

    public InputStream getRequestEntity() {
        if (requestEntity == null) {
            return null;
        }
        
        if (!retryable) {
            return requestEntity;
        }

        try {
            if (!(requestEntity instanceof ResettableServletInputStreamWrapper)) {
                requestEntity = new ResettableServletInputStreamWrapper(
                        StreamUtils.copyToByteArray(requestEntity));
            }
            requestEntity.reset();
        }
        finally {
            return requestEntity;
        }
    }

这段代码源自RibbonCommandContext是在zuul中进行请求转发的时候调用到的,具体的OOM是发生在调用StreamUtils.copyToByteArray(requestEntity));的时候。继续进入方法查找源头。最终经过排查找到了溢出的源头。ribbon转发中的用到了ByteArrayOutputStream的拷贝,代码如下:

    public synchronized void write(byte b[], int off, int len) {
        if ((off < 0) || (off > b.length) || (len < 0) ||
            ((off + len) - b.length > 0)) {
            throw new IndexOutOfBoundsException();
        }
        ensureCapacity(count + len);
        System.arraycopy(b, off, buf, count, len);
        count += len;
    }

可以看到这边有一个ensureCapacity,查看源码:

    private void ensureCapacity(int minCapacity) {
        // overflow-conscious code
        if (minCapacity - buf.length > 0)
            grow(minCapacity);
    }

    private void grow(int minCapacity) {
        // overflow-conscious code
        int oldCapacity = buf.length;
        int newCapacity = oldCapacity << 1;
        if (newCapacity - minCapacity < 0)
            newCapacity = minCapacity;
        if (newCapacity - MAX_ARRAY_SIZE > 0)
            newCapacity = hugeCapacity(minCapacity);
        buf = Arrays.copyOf(buf, newCapacity);
    }

可以看到ensureCapacity做了一件事,就是当流拷贝的时候byte数组的大小不够了,那就调用grow进行扩容,而grow的扩容和ArrayList不同,他的扩容是每一次将数组扩大两倍。

至此溢出的原因就很清楚了,500m文件占用1.6g是因为刚好触发扩容,导致用了多一倍的空间来容纳拷贝的文件,再加上源文件,所以占用了文件的3倍空间。

解决方案

至于解决方案,调整内存占用或者是老年代的占比显然不是合理的解决方案。我们再回头查看源代码,可以看到这个部分

    if (!retryable) {
        return requestEntity;
    }

如果设置的不重试的话,那么body中的信息就不会被保存。所以,我们决定临时先去除上传文件涉及到的服务的重试,之后再修改上传机制,在以后的上传文件时绕过zuul。

追根溯源

虽然找到的原因,并且也有了解决方案,但是我们仍然不知道为什么旧版本是ok的,因此本着追根究底的态度,找到了旧版的zuul的源码。

新版的ribbon代码集成spring-cloud-netflix-ribbon,而旧版的ribbon的代码集成在spring-cloud-netflix-core中,所以稍稍花费点时间才找到对应的代码,检查不同,发现旧版的getRequestEntity没有任何的处理,直接返回了requestEntity

    public InputStream getRequestEntity() {
        return requestEntity;
    }

而在之后的版本中马上就加上了拷贝机制。于是我们去github上找到了当初的那个commit

之后我们顺着commit中给出的信息找到了最初的issue

查看过issue之后发现这原来是旧版的一个bug,这个bug会导致旧版的post请求在retry的时候有body丢失的情况,因此在新版本中进行了修复,当请求为post的时候会对于body进行缓存以便于重试。

至此,我们原原本本的复原了这个bug的全貌以及形成的历史和原因。并且找到适当的解决方案。最后提一句:真的不要用zuul来上传大文件,真的会很糟糕!

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