
导语
通常我们认为,应用是运行在应用服务器之上的,应用服务器不能正常启动,通常和上层应用无关。那么,您有遇到过应用中间件和开发框架组件的启动,会受上层应用影响的怪事吗?这样难得一见的奇案,又是怎么被侦破的呢?本文,作者将邀请您一起看看,朗新技术团队是如何一步一步抽丝剥茧、过关打怪的。

01
问题现象及环境说明
某现场数据库管理员反馈,某一应用近期突然出现测算任务不测算,但是Weblogic Server后台无明显报错,现场数据库管理员也尝试通过重启应用服务器来解决该问题,但结果出现部分Weblogic Server一直处于Starting状态,无法启动到Running状态。
由于应用没有任何报错,所以第一反应是,应用是不是遇到性能问题。正常情况下,几分钟就能完成的启动过程,等了几十分钟,应用服务器还是一直处于Starting状态。
检查了应用和数据库服务器的资源使用情况,也没有明显异常资源消耗。联系开发人员,由于程序近期也未调整,后台也无程序报错,开发人员也只能建议尝试重启。反复重启了几次应用服务器,但万能的重启大法居然也失灵了。
应用启动过程中,Weblogic Server出现了hung【 hung就是挂起、假死的意思,这里的外在表现就是不报错好像也不干活】的情况,但是没有任何报错,这种问题极少发生,看来这个问题需要更进一步的分析和处理。
按照我们分析问题的套路,我们第一步需要收集现场的环境信息。经确认,现场环境信息如下:
应用服务器:RedHat Linux 6.8+ Weblogic10.3.6
数据库服务器:Linux+Oracle11.2.0.4 RAC
部署server:proxyServer、sgrca_app和sgrca_jar
应用程序开发框架:基于UAP框架开发【UAP:Unified Application Platform,全称应用系统统一开发平台,是应用开发、运行、治理平台】

02
问题分析及处理
01
初判问题发生层次?
由于现象是proxyServer无法正常启动,我们查看了proxyServer重启的应用日志,最终停留的状态见下图:

图 1 发布应用状态下重启后日志截图
从最后的日志看,无任何报错,因此,怀疑应用有问题导致Server无法正常启动。但是开发人员认为系统重启前正常,现在重启出现应用服务器启动hung住,如果应用有问题,一般会出现相应的报错。目前没有看到明显应用报错,所以不是程序的问题,而是环境的问题。
于是,首先要解决的就是问题发生的层次。基于从最简单的可能开始分析的思路,我们怀疑是否启动过程中没有清理缓存导致server启动异常。和现场数据库管理员确认是否清理了Weblogic的cache、data、stage、tmp。得到答复是每次都进行了清理。
然后,为了进一步确定到底是应用阻止了Weblogic Server启动还是Weblogic Server本身就有问题,现场数据库管理员采取取消应用发布,只启动Weblogic Server,proxyServer正常启动。

图 2 取消应用发布后weblogic启动日志截图
我们认为应用程序出现问题导致Server无法启动的可能性就很大了。
为进一步印证我们的判断,现场数据库管理员采用新搭环境,尝试在新的proxyServer重新发布程序,问题依然存在。
至此,基本上可以肯定不是Weblogic Server层面的问题,应该是应用启动过程中出现了问题导致Weblogic Server启动hung住。
02
检查系统资源情况
基于应用日志一直没有看到报错信息,我们认为可能只是配置问题或者资源不足问题导致应用无法响应。于是,请现场数据库管理员把系统资源、环境变量、系统参数、防火墙都检查了一遍,确认操作系统都正常。
然后,猜测是不是JVM【JVM:Java Virtual Machine(Java虚拟机)的缩写,JVM是一种用于计算设备的规范,是通过在实际的计算机上仿真模拟各种计算机功能来实现的。】性能问题,根据其他项目经验把:
$JAVA_HOME/jre/lib/security/java.security/securerandom.source=file:/dev/random
改成:
securerandom.source=file:/dev/./urandom
同时更换了JDK版本【JDK:Java Development Kit,Java 语言的软件开发工具包】,发现还是出现hung住。
然后,请现场数据库管理员配合收集了jstack【jstack命令主要用于调试java程序运行过程中的线程堆栈信息,可以用于检测死锁,进程耗用cpu过高报警问题的排查。】输出,没有发现有STUCK的进程,但是发现以下信息:

图 3 数据库操作相关线程堆栈图

图 4 FrameworkLauncher相关线程堆栈图
至此,怀疑数据库语句执行存在问题,导致UAP的FrameworkLaucher无法启动。检查数据库alert日志、表空间使用率、归档日志空间、数据文件读写等,相关指标都正常。
查看数据库服务器性能,发现360entclient进程资源消耗较多,请现场数据库管理员临时停掉。为了排除应用服务器内存不足导致启动慢,调整内存到4G,问题依旧。
03
山穷水尽,剑走偏锋
当我们看到jstack显示FrameworkLaucher的start方法阻塞后,已经有点山穷水尽的感觉了。
从代码来看这是一个线程启动阻塞了,所以,请现场数据库管理员再次把limits都重新检查输出看了是否生效:

图 5 Java进程资源限制图
从上图可以看到,进程限制都正常。至此,我们只知道UAP Framework启动时阻塞导致Weblogic Server启动hung住,到底是什么导致UAP Framework启动阻塞还不清楚。
然后,就希望通过抓包看看是否能有所发现,排除一些干扰流量外,经确认,由于Server没有正常启动,应用http端口都不存在,至此,通过抓包协助问题分析的方法行不通,看来,我们还需要更多辅助信息协助分析问题。
04
柳暗花明 or 疑雾重重?
为了能获得更多的日志,和现场数据库管理员沟通调整应用日志级别为DEBUG。重启应用,发现还是不能成功启动,但是日志打印多了以下信息:

图 6 应用服务器Java消息服务相关报错信息图(启动失败)
和现场数据库管理员确认本地是否存在ActiveMQ【ActiveMQ:一种消息中间件】,得到的反馈是不知道有ActiveMQ,也没有部署过ActiveMQ,查看了上线时的系统逻辑架构图,发现确实不存在ActiveMQ。
咨询开发人员,怀疑是新增功能。考虑关闭ActiveMQ配置,通过和开发人员沟通,未找到该功能参数开关。几经尝试调整,在2020-3-17 16:53这次重启老环境proxyServer,打开了DEBUG日志,发现尽管ActiveMQ的报错依然存在,但是这次应用居然启动成功。截图如下:

图 7 应用服务器Java消息服务相关报错信息图(启动成功)
针对这次成功启动过程,我们仔细分析了这次的日志,发现DUBUG模式下日志除ActiveMQ报错外,还有以下数据库和内存溢出报错:

图 8 应用服务器数据库相关报错信息图

图 9 应用服务器内存溢出相关报错信息图
针对java.sql.SQLException报错,怀疑JDBC驱动版本有问题,请现场数据库管理员使用新的11.2.0.4的JDBC驱动,加入到应用的lib目录,该报错问题解决。
针对java.lang.OutofMemoryError: Gc overhead limit exceeded报错,由于现场服务器内存充足,建议现场数据库管理员将原来JVM配置的-Xms1536m -Xmx1536m调整为-Xms4096m -Xmx4096m
同时添加了-XX:+HeapDumpOnOutOfMemoryError,然后重启。发现应用服务器没有启动成功,也没有OutOfMemory报错,应用一直处于Starting状态。
这个时候,看到了更多的日志,原以为柳暗花明了,哪知道还是迷雾重重。看来我们需要更多外援了。
05
大神导入,协作打怪
解决了一个简单的问题后,又陷入僵局。于是邀请公司的应用问题分析专家参与分析,通过 jstack日志,也迅速定位到了UAP一直在初始化没start起来。
现场数据库管理员又把内存调整到1536M后再次重启,20分钟后应用居然又启动成功了。查看启动成功的日志,针对ActiveMQ的报错,由于无论是否能成功启动,都有这个报错,所以我们一致认为,不是这个问题导致应用不能启动。
然后就对应用启动成功和应用启动不成功的日志进行对比,发现应用启动不成功的时候任务调度的bundle容器没初始化好。至此,基本定位出了问题是由任务调度导致的Weblogic Server无法进入Running状态。
由于我们之前添加了OOM【OOM:Out Of Memory,简单的说就是分配的内存已用完】的-XX:+HeapDumpOnOutOfMemoryError参数,当内存设置为1536M后,OOM再次出现了,dump文件【dump文件是进程的内存镜像文件】也正常生成了。
通过分析dump,可以看到org.quartz.impl.jdbcjobstore.FiredTriggerRecord对应返回对象接近200万:

图 10 对象集直方图
进一步跟踪发现线程执行情况如下:

图 11 定位产生大量对象SQL语句图
可以看到大量对象是以下语句产生的:
SELECT * FROM T_TD_FIRED_TRIGGERS WHERE SCHED_NAME = ‘scheduler’ AND INSTANCE_NAME = ?
然后请现场数据库管理员确认T_TD_FIRED_TRIGGERS表的记录数,该表用于存放已触发的任务记录,一般根据线程控制写入,发现已触发的任务有250万条记录。
至此,基本可以确认,出现任务调度异常堆积,导致应用启动出现OOM。接下来我们需要对Quartz【Quartz 是一个完全由 Java 编写的开源作业调度框架,该系统的任务调度是基于Quartz实现的。】特别熟悉的专家协助分析解决方案了。同时联系业务专家和开发人员协助分析能否对该表进行清理。
通过现场数据库管理员配合专家对数据进行确认,目前的任务都是补偿任务,最终得出结论是T_TD_FIRED_TRIGGERS表本身记录存在问题。可能的原因是任务执行异常后,并发控制存在问题导致任务未正常执行时,还是会不断增加任务,导致该表记录数明显异常。可以备份后进行清理。
经过对T_TD_FIRED_TRIGGERS这张表进行清理后,使用jrocket1.6.0_211的JDK,JVM内存设置4096M,重新启动应用,不到1分钟,3个server都成功启动。任务也开始正常执行。
至此,大神导入,协作打怪,任务圆满收关。

03
复盘
本案例经过测试和排查,最终定位问题是应用的任务调度的并发控制机制,在特定情况下会导致数据库中任务调度相关数据异常,由于异常处理机制和错误恢复机制不完善,影响了UAP Framework初始化,从而导致Weblogic Server无法正常启动。
通过这个案例,也提醒我们开发人员需要特别关注代码中的异常处理机制和错误恢复机制,确保调度任务出现问题时,不至于重复调度产生大量垃圾数据,最终直接影响系统运行。
本案例属于一个相对特殊的应用服务器启动故障的案例。通常,我们遇到应用服务器启动的问题,往往都会有相关的报错。针对这类有明确的报错信息的问题,我们的分析处理流程大致如下图:

图 12 常见应用问题分析处理流程图
本次问题由于没有任何的报错信息,给我们分析查找可能的原因带来了困难。针对这种无明确的报错信息的问题,我们需要充分利用对比分析和排除法来协助定位可能的原因,从而找到正确的解决方案。回过头来看,本次问题分析和处理有以下三个关键阶段:
1. 确定问题发生层次,明确应用程序是问题分析的目标;
2. 问题发生点定位,明确任务调度导致server无法启动;
3. 深入分析数据,评估处理方案的可行性和风险。
针对这三个阶段,总结其中的关键点如下:第一个阶段,现场数据库管理员通过对比分析和排除法,确定问题发生的层次在应用层,明确了工作目标,这个问题也说明了UAP开发的程序并不是在Weblogic server启动后才加载,这点要注意;第二个阶段,通过检查系统资源,明确数据库服务器、应用服务器本身不存在性能问题。重点工作内容转向代码层面分析,通过jstack初步确定阻塞的java代码,通过开启DEBUG日志,看到了更多的信息,解决了潜在可能的问题。更加缩小了问题范围。当OOM日志出现时,应用专家使用MAT【MAT:Memory Analyzer Tool,是一种快速,功能丰富的Java堆分析工具。】分析工具快速定位问题原因;第三个阶段,通过任务调度组件方面的专家介入,深入分析数据,评估处理方案的可行性和风险。快速确定解决方案,从而问题迎刃而解。
通过这个应用启动故障的分析,个人认为,有以下经验可以借鉴:
1. 分析问题要从简单入手,大胆假设,小心求证,排除法是非常简单有效的方法;
2. 定位问题要理清思路,先明确问题发生层次,通常要考虑的几个层次:操作系统及服务器资源、网络、数据库、应用等;
3. 分析问题时需要尽可能详细的日志,如:DEBUG日志、OOM日志、DataSource日志等,要注意日志细节;
4.应用类问题分析常用命令和工具需要掌握,如:top【top -Hp pid】、jstack【jstack PID】、kill -3 PID、反编译工具【如:Java Decompiler】、java内存堆栈分析工具(如:MAT);
5.对于系统运维而言,有以下几点需要注意:对于我们运维的系统,需要熟悉系统的逻辑架构、部署组件和调用及依赖关系;对于系统涉及到的一些组件,要了解工作机制和原理;对于一些重要组件的核心数据表的数据量级要心中有数;
6.相信团队的力量,术业有专攻,协作更加高效。

04
结语
应用程序的设计开发需要有完备的异常处理机制和错误恢复机制,这样才能保证应用的可靠性。本案例最终得以解决,也让我们深切体会到,术业有专攻,尤其在面对大规模复杂性系统开发/运维的时候,多方协作,非常重要。本案例对于应用程序导致应用服务器无法启动,属于一个典型案例,期望给大家一些启发。
文 | 陈迪曙 朗新科技集团系统集成部
注:文章仅代表作者观点,欢迎转发和评论。转发、转载、转帖等须注明“稿件来源:朗新研究院”违者朗新研究院将依法追究责任,谢谢!
延伸阅读
专题|序言:五年规划回头看
【电力大数据】浅谈电力行业元数据管理
【技术分享】服务网关产品的探索与实践
设计|2019桌面框架系统设计优化&升级
【能源服务】当电力营销遇到现货市场结算
【供电服务】浅谈“1+2”电力现场服务机制的应用模式
[案例解读]基于四维度模型的盒马服务创新借鉴
【新基建 新营销】电力营销精细化运营系列(一)
