我们都会犯错误,但有些错误看起来太可笑了,我们想知道怎么会有人,更不用说我们自己,会做出这样的事情。当然,只有在事后才注意到这一点。下面,我将描述我们最近在一个应用程序中犯下的一系列错误。有趣的是,最初的症状表明一种完全不同于实际存在的问题。
从前一个沉闷的午夜
午夜过后不久我就被监控系统的警报吵醒了。在我们的PPC(pay-per-click)广告系统中,一个负责索引广告的应用程序显然已经连续重启了好几次。在云环境中,单个实例重启是正常事件,不会触发任何警报,但这次多个实例在短时间内重启超过了阈值。我打开我的笔记本电脑,一头扎进应用程序的日志。
一定是网络
当服务尝试连接到ZooKeeper时,我看到了几个超时。我们使用ZooKeeper(ZK)来协调多个实例之间的索引,并依赖它来保持健壮性。显然,Zookeeper的失败会阻碍索引的成功,但它不应该导致整个应用程序的死亡。尽管如此,这是一个如此罕见的情况(我第一次看到ZK停产),我想也许我们确实没能优雅地处理这个案子。我叫醒了负责Zookeeper的值班人员,让他们检查一下发生了什么事。
同时,我检查了我们的配置,发现ZooKeeper连接的超时在几秒钟的范围内。显然,ZooKeeper已经完全死了,而且考虑到其他应用程序也在使用它,这意味着严重的麻烦。我给另外几个显然还不知道这个问题的团队发了信息。
Zookeeper团队的同事回复我说,从他的角度来看,一切都很正常。由于其他用户似乎没有受到影响,我慢慢意识到ZooKeeper并不是罪魁祸首。日志清楚地显示了网络超时,所以我叫醒了负责联网的人。
网络团队检查了他们的指标,但没有发现任何有趣的东西。虽然网络的一个部分甚至一个机架都有可能与其他部分断开,但他们检查了运行我的应用程序实例的特定主机,没有发现任何问题。在此期间,我检查了一些旁门左道的想法,但没有一个奏效,我束手无策。它变得很晚了(或者说是很早),并且,独立于我的行为,重新启动变得不那么频繁了。由于这个应用程序只影响数据的新鲜度,而不影响它的可用性,因此我们决定让这个问题等到早上。
一定是垃圾收集
有时候睡一觉,用一个全新的思维重新面对一个棘手的问题,这是个好主意。没有人知道发生了什么,服务表现得非常神奇。后来我才恍然大悟。Java应用程序中魔法的主要来源是什么?当然是垃圾收集。
对于这种情况,我们默认保持GC日志记录。我很快下载了GC日志并启动了Censum。就在我眼前,一个可怕的景象打开了:每15分钟发生一次完全的垃圾收集full gc,造成20秒长的时间停顿。难怪连接到ZooKeeper超时,尽管ZooKeeper或网络没有问题!
这些暂停也解释了为什么整个应用程序总是死机,而不仅仅是超时并记录错误。我们的应用在Marathon内部运行,它定期轮询每个实例的healthcheck端点,如果端点在合理的时间内没有响应,Marathon会重新启动该实例。
知道问题的原因是成功的一半,所以我很有信心这个问题会很快得到解决。为了解释我的进一步推理,我不得不多说一点关于Adventory是如何工作的,因为它不是您的标准微服务。
Adventory用于将我们的广告索引到ElasticSearch中。这个故事有两个方面。一是获取必要的数据。为此,应用程序通过Hermes接收来自系统其他几个部分的事件。数据保存到MongoDB集合中。流量最多是每秒几百个请求,而且每个操作都相当轻量级,因此尽管这肯定会导致一些内存分配,但并不需要大量资源。故事的另一面是索引本身。此过程定期启动(大约每两分钟一次),并使来自所有不同MongoDB集合的数据使用RxJava进行流式传输,组合成非规范化记录,并发送到ElasticSearch。应用程序的这一部分更像是脱机批处理作业,而不是服务。
在每次运行期间,都会重建整个索引,因为数据通常会有太多更改,因此增量索引不值得大惊小怪。这意味着大量的数据必须通过系统,并且需要进行大量的内存分配,这迫使我们在使用流的情况下使用12gb的堆。由于堆很大(而且是当前完全支持的堆),我们选择的GC是G1。
我以前使用过一些分配大量短期对象的应用程序,通过在默认值的基础上增加-XX:G1NewSizePercent
和-XX:G1MaxNewSizePercent
来增加年轻代的大小,这样年轻的GC可以处理更多的数据,而不是移到老的代,因为Censum表现出了很多过早的牢狱之灾。这也与一段时间后发生的完整GC收集一致。不幸的是,这些设置一点帮助也没有。
接下来我想到的是,也许生产者生成的数据太快,消费者无法消费,从而导致记录的分配速度超过了释放记录的速度。我试图通过减小负责生成非规范化记录的线程池的大小,同时保持发送给ES的使用者数据池的大小不变,从而降低存储库生成数据的速度。这是施加反压力的原始尝试,但也没用。
一定是内存泄漏
在这一点上,一位头脑冷静的同事建议我们首先做我们应该做的事情,即查看堆中实际有哪些数据。我们建立了一个开发实例,其数据量与生产中的相当,并按比例缩放堆。通过使用jvisualvm连接到它并运行内存采样器,就是dump文件,我们可以看到堆中对象的近似计数和大小。一眼就能看出,我们的领域广告对象的数量远远超过了它应该有的数量,并且在索引过程中一直在增长,达到了一个与我们正在处理的广告数量惊人相似的数字。但是…这不可能。毕竟,我们使用RX流式传输记录正是出于这个原因:为了避免将所有数据加载到内存中。
随着越来越多的怀疑,我检查了代码,这是大约两年前编写的,从那时起就再也没有认真过。瞧,我们实际上是在把所有数据加载到内存中。当然不是故意的。当时对RxJava还不够了解,我们想用一种特定的方式并行化代码,并决定使用CompletableFuture
和一个单独的执行器,以便从主RX流中卸载一些工作。但是,我们必须等待所有CompletableFutures
完成…存储对它们的引用并调用join()
。这导致对所有future
的引用,以及对它们引用的所有数据的引用都保持活动状态,直到索引结束,并阻止垃圾回收器提前释放它们。
真的那么糟糕吗?
这显然是个愚蠢的错误,我们对这么晚才发现它感到厌恶。我甚至记得很久以前有一次关于应用程序需要12GB堆的简短讨论,这似乎有点过分了。但另一方面,这个代码已经运行了将近两年,没有任何问题。在这一点上,我们能够相对轻松地修复它,而如果我们在两年前尝试修复它,可能会花费我们更多的时间,而那时对于这个项目来说,有很多工作比节省几GB内存更重要。
因此,虽然在纯技术层面上,这么长时间存在这个问题确实令人遗憾,但从战略的角度来看,尽管怀疑效率低下,但让它独善其身或许是更明智的选择。当然,另一个考虑因素是问题一旦曝光的影响。我们侥幸逃脱了,对用户几乎没有任何影响,但情况可能更糟。软件工程是关于权衡的,决定不同任务的优先级也不例外。
仍然不工作
有了更多的RX经验,我们能够很容易地摆脱复杂的未来,重写代码以只使用RX,在这个过程中迁移到RX2,并且实际地流式传输数据,而不是在内存中收集数据。更改通过了代码评审,并在开发环境中进行了测试。令我们惊讶的是,该应用程序仍然无法使用较小的堆执行索引,内存抽样结果显示,内存中保存的广告数量比以前少,而且不仅增长,有时还会减少,因此并不是全部收集在内存中。不过,数据似乎也没有被传输。
现在是什么?
相关的关键字已经在这篇文章中使用了:背压。当数据流化时,生产者和消费者的速度通常不同。如果生产者比消费者快,而且没有任何东西迫使它放慢速度,它将继续产生越来越多的数据,而这些数据不能以同样快的速度被消费掉。将出现一个不断增长的缓冲区,等待消费的未完成记录,这正是在我们的应用程序中发生的情况。背压是一种机制,允许一个缓慢的消费者告诉快速生产者放慢速度。
我们的索引流没有背压的概念,只要我们将整个索引存储在内存中,这就不是问题。一旦我们解决了一个问题,并开始真正地传输数据,另一个问题——缺乏背压——就变得显而易见了。
这是我在处理性能问题时见过多次的一种模式:修复一个问题会暴露出另一个你甚至不知道的问题,因为另一个问题隐藏了它。你可能不知道你的房子有消防安全问题,如果它经常被洪水淹没。
修复
在RXJava2中,原始的Observable类被分成不支持背压的Observable和支持背压的Flowable。幸运的是,有一些巧妙的方法来创造流动性,给他们提供了开箱即用的背压支持。这包括从非反应性来源(如Iterables)创建流动性。将这些流动性结合在一起产生的流动性也支持背压,因此只需固定一个点就可以很快地支持整个流的背压。
有了这个改变,我们能够将堆从12GB减少到3GB,并且仍然让应用程序像以前一样快速地完成它的工作。我们仍然得到一个完整的GC,每几个小时暂停一次,大约2秒,但这已经比我们之前看到的20秒暂停(和崩溃)要好得多。
再次调整GC
然而,故事还没有结束。在查看GC日志时,我们仍然注意到许多过早使用寿命的情况,大约为70%。尽管性能已经可以接受,但我们试图消除这种影响,希望同时也能阻止完全垃圾回收。
当一个对象寿命很短,但无论如何都被提升到老年代时,就会发生过早的tenured(也称为过早提升)。这些对象可能会影响GC性能,因为它们填充了通常比新一代大得多并且使用不同GC算法的旧一代。因此,过早晋升是我们要避免的。
我们知道我们的应用程序在索引过程中会产生大量的短期对象,所以一些过早的推广并不令人意外,但其程度却是如此。在处理一个创建大量短期对象的应用程序时,首先想到的是简单地增加年轻一代的规模。默认情况下,G1GC可以自动调整代的大小,允许新一代使用5%到60%的堆。我注意到,在live应用程序中,年轻一代和老一代的比例在很大范围内一直在变化,但仍然继续检查,如果我提高了两个界限,会发生什么:-XX:G1NewSizePercent=40
和-XX:G1MaxNewSizePercent=90
。这并没有起到什么作用,事实上它使事情变得更糟,几乎在应用程序启动后立即触发了完整的GCs。我尝试了其他一些比率,但我能得到的最好结果只是增加G1MaxNewSizePercent
而不修改最小值:它与默认值一样有效,但并不更好。
在尝试了一些其他的选择之后,我放弃了,并给Kirk Pepperdine发了电子邮件,他是Java性能方面的著名专家,我有机会在Devoxx会议上和Allegro的培训课程中见到他。在查看了GC日志并交换了一些电子邮件之后,Kirk建议进行一个实验,将-XX:g1mixedCliveThresholdPercent
设置为100。此设置将强制G1GC混合集合清除所有旧区域,而不管它们被填充了多少,因此也将从年轻的对象中移除任何过早保留的对象。这应该可以防止老年代在任何时候都填满并导致一个完整的GC。然而,一段时间后,我们再次惊讶地发现垃圾回收已经运行完毕。Kirk总结说,这种行为(他在其他应用程序中看到的)是G1GC中的一个缺陷:混合收集显然无法清理所有垃圾,因此允许垃圾累积到完全GC。他说他已经和甲骨文联系过了,但他们声称这不是一个bug,我们观察到的行为是正确的。
结论
最后我们做的只是将应用程序的堆大小增加一点(从3 GB增加到4GB),然后完全的垃圾收集就消失了。我们仍然看到很多过早的tenuring,但由于现在的表现还行,我们不再那么在意了。我们可以尝试的一个选择是切换到CMS(Concurrent Mark Sweep)GC,但由于它现在已被弃用,我们宁愿尽可能避免使用它。
那么这个故事的寓意是什么呢?首先,性能问题很容易使您误入歧途。一开始似乎是ZooKeeper或网络问题,结果是我们自己的代码出错了。即使在意识到这一点之后,我采取的第一步也没有经过深思熟虑。在详细检查到底发生了什么之前,我开始优化垃圾收集,以避免出现完整的GC。这是一个常见的陷阱,所以要小心:即使你有一个做什么的直觉,检查你的事实,并再次检查,以避免浪费时间解决一个不同于你实际处理的问题。
第二,把性能做好真的很难。我们的部署在很长一段时间后才被明确地定义为“表面”功能,但在测试开始后,这些功能并没有完全满足wise的要求。由于通常很难忠实地再现您的生产环境,所以您常常被迫在生产中测试性能,而不管这听起来有多糟糕。
第三,解决一个问题可能会让另一个潜在的问题浮出水面,迫使你继续深究下去,比你预期的要长得多。我们没有背压这一事实足以破坏这个应用程序,但在我们修复内存泄漏之前,它并没有变得可见。
除特别注明外,本站所有文章均为老K的Java博客原创,转载请注明出处来自https://javakk.com/1055.html
暂无评论