Android-记一次内存泄漏定位和解决的过程

我司在做一款公交车上的车载应用,功能主要包含1.自动到离站语音播,2.报排班显示,3.Led,lcd,按键板等硬件通信 和其他功能不一一列举了。功能复杂度其实还挺高的,涉及 Jni,socke 长连接,多线程等技术栈。项目初期不是我开发的,而是由外包给别的团队。项目中期某些不可控因素,才把项目拉回来自己做。等项目完全上线能用后不久,同事也都离职了,剩下我一个人孤苦伶仃的去维护。熟悉架构,review兄弟们的代码逻辑。领导也多次要求我去熟悉他们的代码,看不懂的直接按自己的想法重构掉。这下好了, 我的2021年大半年的时间都在改进这个项目。

最近收到一些死机的报修反馈:机子卡死,不能自动报站。其实接到这种问题的第一反应是捞和trace。先说说我们的车载机设备的配置情况。系统android 6.0,双核cpu = 10年前的手机cpu的性能,内存 2G ddr3,存储16G。我对这样的硬件其实一直怨声载道。因为我们的应用复杂度 和实际运行对硬件的需求是挺高的,频繁的io,频繁线程切换。硬件部门给的回复是:跑我们的应用足够了。也许越差的硬件,越能激发一个coder的潜力吧。于是我把抱怨 就仅仅当成是抱怨。

回到上面提到的问题。通过查看日志立马发现了一些问题,问题1:

java.util.concurrent.TimeoutException: android.os.BinderProxy.finalize() timed out after 10 seconds
  at android.os.BinderProxy.destroy(Native Method)
  at android.os.BinderProxy.finalize(Binder.java:547)
  at java.lang.Daemons$FinalizerDaemon.doFinalize(Daemons.java:202)
  at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:185)
  at java.lang.Thread.run(Thread.java:818)

拿到以上异常信息后,我给产品的回复是系统卡死了,暂时无法定位问题原因。作为一个bug creator,pm听到我的回复肯定会说:一天时间够不够? 我也只能回复:no?problem !看完crash日志 一头雾水。继续查看运行时log。马上查到一些端倪(问题2):

1636519834003|I|BUSPAD_TAG|GWS=lat/lng: (30.24580982311159,120.20578926205371) ,精度:1.09,时间1636519812000 ,定位类型:1,speed = 4.01
1636519835008|I|BUSPAD_TAG|GWS=lat/lng: (30.24580982311159,120.20578926205371) ,精度:1.09,时间1636519812000 ,定位类型:1,speed = 4.01
1636519836000|I|BUSPAD_TAG|GWS=lat/lng: (30.24580982311159,120.20578926205371) ,精度:1.09,时间1636519812000 ,定位类型:1,speed = 4.01
1636519837001|I|BUSPAD_TAG|GWS=lat/lng: (30.24580982311159,120.20578926205371) ,精度:1.09,时间1636519812000 ,定位类型:1,speed = 4.01
1636519839936|I|BUSPAD_TAG|GWS=lat/lng: (30.24580982311159,120.20578926205371) ,精度:1.09,时间1636519812000 ,定位类型:1,speed = 4.01...

这些是连续的gps数据,我去!连续好几秒 中location都是同一个,时间戳都是一样的,这gps点都没动啊。难怪不会报站。tip:我们的自动报站算法是基于精准连续定位的前提。这种情况 是个人都知道肯定没法报站了。然后我又开始甩锅了,这锅给系统好?还是gps模组好?反正不能甩给 我自己写的代码。既然定位问题这么严重,去后台看看车辆的运行轨迹吧。看了轨迹我心里有底了。有另外一辆车和这辆车的编号冲突了。于是两辆车互相掉线,上线, 掉线,上线..。轨迹中有了两辆车的轨迹的交集。但是就是掉线重连,难道会导致软件卡死,甚至系统卡死嘛??我一脸懵逼的开始了我的卡顿元凶追寻之旅。

我在测试设备上 和 模拟器(android 10)上运行最新的代码。配置相同的测试编号。观察打印的日志,我发现测试设备和monitor只要有一方掉线,打印出来的gps点的日志的时间戳就会很不均匀,原本应该是1秒一次,顶多有个0-100ms左右的波动。软件掉线后的gps点不稳定到会有2s的误差,甚至2-4秒才出一个点。我坚信自己的gps处理逻辑不存在卡ui的情况。基本都把老的逻辑用协程优化了。可能真的是掉线会导致系统卡顿,然后影响gps模组和gpsprovicer的数据交互的效率。带着这份怀疑 ,我先从分析app的内存使用情况入手。模拟器的性能更好,我选择从模拟器着手分析。于是打开profiler。本来只是有点卡顿,一打开profile的那一刻,直接软件闪退,给了个OOM的crash log:

java.lang.OutOfMemoryError: Failed to allocate a 24 byte allocation with 16 free bytes and 16B until OOM, target footprint 16777216, growth limit 16777216

难道最上面提到的 java.util.concurrent.TimeoutException 和这个有关联?这是我第一反应。于是对测试设备也进行profile,果然 也产生了crash,不过它的crash 日志不是OOM 而是TimeoutException。基于我之前看的《深入理解Java虚拟机》这本书,我大胆猜测是6.0系统与10.0系统的gc机制,不一致,高版本JVM对OOM的定位更加清晰。

如何处理:java . util . concurrent。TimeoutException: android.os.BinderProxy.finalize()在10秒错误后超时? 这篇文章让我更加确信,TimeoutException是gc超时导致的,频繁FullGC,导致了系统的卡顿,不用说 肯定内存泄漏了嘛。“找到那个导致内存泄漏的根源” 是我此刻内心的唯一想法。

先定位问题:capture heap dump 。
pic01.png

分析:heapdump中映入眼帘的第一反应是。这byte[] 数据也太大了,一半的应用内存都被它占用了。联想到掉线会引发卡顿,这部分数据应该是io操作 或者等待收发的数据队列(用的LinkedBlockQueen)产生的。点击byte[]这一行,查看更细致的对象内存分配情况。
pic02.png

看到Shallow Size那一列,1048576这个数据,我没仔细算,预估应该是 1024 * 1024的积。于是开始全局搜“1024 * 1024"。
pic03.png

看到这个搜索结果 我很惊喜,因为它和前一张图中的第三步指向的内存对象ReaderImpl完全吻合。那应该就是它了。这么快就找到它了,这也太简单了。但是这只是定位到了大对象,并不代表它就是内存泄漏的根源。于是我观察了几分钟的内存动态变化情况。自动触发gc的频率确实很高。多次执行heap dump后,这样的大对象果然越来越多。 大概大于8个后 就会出现OOM。这么说它就是最大的嫌疑人了。coder的必经之路:代码分析 ,代码优化。况且这些都是前辈祖传下来的。乘机好好理理。

优化前的代码贴出来了:

  @Override
    public void read() throws RuntimeException {
        OriginalData originalData = new OriginalData();
        try {
            InputStream is = mInputStream;
            DataInputStream input = new DataInputStream(is);
            byte[] b = new byte[1024 * 1024];
            ByteArrayOutputStream bos = new ByteArrayOutputStream();

            int len = 0;
            while (true) {
                len = input.read(b);
                bos.write(b, 0, len);
                originalData.setBodyBytes(bos.toByteArray());
                mStateSender.sendBroadcast(IOAction.ACTION_READ_COMPLETE, originalData);
                bos.reset();
            }
        } catch (Exception e) {
            ReadException readException = new ReadException(e);
            throw readException;
        }
    }

看到这个while循环了吗,想想heap中不断增多的对象。细思极恐!!理论分析:socket io流 不需要多个reader对象。甚至在我们的项目中就不应该有多个reader对象。掉线重连后应该尝试重用该对象,或者把对象free掉 再重新new。 那我就从对象的创建入手 。

//io线程管理
private void resolveManager() throws IOException {
        ...
        mManager = new IOThreadManager(...);
        mManager.startEngine();
        ...
}

 public IOThreadManager(...) {
        ...
        initIO();
}

private void initIO() {
        ...
        mReader = new ReaderImpl();
        ...
}

创建的流程也比较容易定位,reconnect后执行resolveManager(),执行链每次都会 new ReaderImpl();如果前一个对象来不及GC,那么出现两个对象,这是很正常的情况。极端情况下,频繁掉线重连,产生多个大对象 我也能理解。但是目前的重新连接的频率也控制在10s。所以 出现那么多没被回收的对象,那么肯定是有严重的泄漏问题。立马开始寻找泄漏的原因。回到上面贴的代码:

  @Override
    public void read() throws RuntimeException {
        OriginalData originalData = new OriginalData();
        try {
            InputStream is = mInputStream;
            DataInputStream input = new DataInputStream(is);
            byte[] b = new byte[1024 * 1024];
            ByteArrayOutputStream bos = new ByteArrayOutputStream();

            int len = 0;
            while (true) {
                len = input.read(b);
                bos.write(b, 0, len);
                originalData.setBodyBytes(bos.toByteArray());
                mStateSender.sendBroadcast(IOAction.ACTION_READ_COMPLETE, originalData);
                bos.reset();
            }
        } catch (Exception e) {
            ReadException readException = new ReadException(e);
            throw readException;
        }
    }

在while循环中,如果io流断开。write操作会抛出异常。

 java.net.SocketException: sendto failed: EPIPE (Broken pipe)

于是while循环断开。理论上这时候这个对象就没有用了。重连后 通过重新创建,然后继续执行read操作。难道有什么原因导致它又进入到read方法,如此反复。

    @Override
    public final void run() {
        try {
            isShutdown = false;
            beforeLoop();
            while (!isStop) {
                this.runInLoopThread();
                loopTimes++;
            }
        } catch (Exception e) {
            if (ioException == null) {
                ioException = e;
            }
        } finally {
            isShutdown = true;
            this.loopFinish(ioException);
            ioException = null;
            SLog.w(threadName + " is shutting down");
        }
    }

    @Override
    protected void runInLoopThread() throws IOException {
        mReader.read();
    }

看了好几遍其中的逻辑,似乎并没有什么问题。在异常的时候跳出read方法,抛异常给外部循环。最终停掉整个循环。此时的对象 应该是能被系统回收的。除非外层的run方法没有catch到异常。简单查看日志发现 ,read
方法中的自定义ReadException,并不是IOException。那么那runInLoopThread的throws IOException 改成throws RunTimeException。既然要优化,就把里面的实现逻辑全优化了。
优化后代码贴下面。

@Override
    protected void runInLoopThread() throws RuntimeException {
      //read操作进去前,先判断连通情况,减少不必要的对象的创建。否则直接抛异常,中断循环线程。
        if (SocketManager.getInstance().isConnect()) {
            mReader.read();
        }else throw new ReadException();
    }


ReaderImpl.java 
//考虑到未来对象重用,把read方法中的对象提取出来复用
    byte[] b = new byte[1024 * 1024];
    OriginalData originalData = new OriginalData();
    InputStream is = mInputStream;
    DataInputStream input = null;
    ByteArrayOutputStream bos =  null ;
    //接收byte数组
    @Override
    public void read() throws RuntimeException {

        try {
        //  如果复用 那么byte[]数据肯定得重置掉
            ByteUtil.resetBytes(b);
            input = new DataInputStream(is);
            bos = new ByteArrayOutputStream();
            int len = 0;
            while (true) {
                len = input.read(b);
                if (len>0) {
                    bos.write(b, 0, len);
                    originalData.setBodyBytes(bos.toByteArray());
                    mStateSender.sendBroadcast(IOAction.ACTION_READ_COMPLETE, originalData);
                    bos.reset();
                }
            }
        } catch (Exception e) {
            ReadException readException = new ReadException(e);
            b= null;
            e.printStackTrace();
            throw readException;
        }finally {
           if (bos!=null) {
               try {
                   bos.reset();
               } catch (Exception e) {
                   e.printStackTrace();
               }
           }
        }
    }

    @Override
    public void close() {
        super.close();
//  b对象应该是随着Reader对象一起回收的,这里置成null ,我就是想告诉系统,你随时来收了我吧。我绝对不浪费土地,此处的用处 应该不大。
        b = null;
    }

run一下,profile一下,嘿嘿嘿!!立马开心的跟领导汇报战况去了。
以上是我最近遇到的OOM问题定位和解决的过程。仅供问题定位和解决的一些思路。针对部分场景OOM问题的寻根也许这边文章能小小帮助到你。

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

推荐阅读更多精彩内容