cmd设置不合理导致的系统卡死

（一）问题现象

4月份出现多次卡顿，据现场人员描述如下“控制台卡死了，打开的weblogic的窗口就无响应了，操作系统点击菜单就会过个半分钟才会弹出来页面，整体操作系统都是慢；从生产环境还原下来的数据库和程序，做模拟投产就卡了；有时重启了以后，一两个小时就卡了，有的时候半天才会卡；排查的weblogic内存，数据库，控制台的日志；五一没有出现卡顿情况”。

（二）原因

cmd窗口缓冲区设置过大问题;

（三）分析过程

1．检查服务器配置

5月9日检查了14服务器，发现除了老产品，还有2个数据库实例、2个P6等其他服务，具体内存分布如下图：

其中可用内存4120M，其中仅有1347M空闲，2773M一般是可释放的文件缓存部分（用于提高文件如日志读写性能），其次再看老产品 部分，已申请2.9个G，根据实际使用情况只有1.1个G

也就是说要到达JVM配置中的3G ,要从额外的可用内存中划出2个G左右，那就要占光空闲内存并占用本应该缓存文件的部分内存，单从这点来看降低了文件读写效率；其次，window server 2008 OS内核要达到最佳性能，对硬件要求中，最佳内存应大于等于2G。一句话来说就是为了达到JVM最大的内存3G和OS内核达到最佳的性能，完全牺牲了读写文件的性能，因此怀疑物理内存问题引起性能问题。

2．检查历史记录

现场人员提供了案发当天的资源管理器记录，如下截图

内存还剩47%，比较充足，可排除物理内存是主因。

3．检查运行时堆栈情况

在卡死时分析堆栈，发现37个阻塞情况，大都卡在打印cmd控制台,有理由怀疑打印过多导致线程阻塞（打印控制台是串行的），如果是用户页面请求就会导致等待。

4．检查cmd控制台问题

A.简述cmd控制台打印机制

cmd控制台程序是操作系统的一部分，一般cmd脚本执行至少启动了2个进程，当启动weblogic服务器时, 除了启动我们关注的老产品 JVM进程，还开启了一个主窗口，用于输出信息，如下

当java应用程序中指定输出到控制台时，就是通过IO把日志传输给控制台窗口进程，由主机进程接收日志后调用另外一个显卡驱动程序打印到窗口中，流程如下图所示：

cmd窗口有两个重要属性：屏幕缓存大小和窗口大小。窗口大小顾名思义，屏幕缓存大小的宽和高指定了传输给显卡的字符数据，显卡将字符打印在cmd窗口中。 以下是我本地的截图，如下图：

从流程中可知，如果cmd程序卡死，当java应用程序的同步打印日志数据时，也会卡着不动。

B.cmd控制台打印问题梳理

首先，从现场人员反馈中得知4月份出现过窗口卡死，也就是cmd程序卡死；

其次，5月11日，实施进行测试时发现窗口白屏，那就是cmd程序或显卡处理异常，如下图

空白区域的字符是“异常字符”，也就是cmd向显卡渠道传输了异常的数据，这么说是因为cmd程序每次白屏时也假死了，进程假死时的行为是不会完全受控的，这样理解也说得通（宁愿相信是数据问题，不可能显卡问题，如果是显卡问题那所有的都有的计算机的显示都有问题）。

通过此阶段的分析，明确了控制台白屏、页面无法访问现象大概率跟cmd程序异常有关，cmd异常是自身的程序问题还是cmd接收的过多或过快的数据导致运行异常， 接下来尝试复现问题。

5．复盘cmd异常问题

以下用14环境描述10.2.151.14服务器，2环境描述10.2.151.2。

A.还原14环境

回退修改的JVM参数，还原到4月份的情况(JDK1.6,内存3G),同时部署的应用列表如下：

B.观察定时任务产生数据时的程序状态

首先，回退后不做任何页面操作，只有DMS、BMS定时任务定时产生数据发送cmd,观察cmd运行一段时间，出现白屏情况，cmd程序也是卡死的，如下图：

此时物理内存占用76%，java应用程序占用1.1G，未达道最大3G，而cmd程序是假死状态。用jconsole连接java应用程序，观察jvm状态一切正常。

截取了cmd卡死时间段内，动态检测的JVM CPU使用情况，可以发现跟jvm相关的user ,system极低，而服务器的其他应用machine使用比较频繁，从运行轨迹来看大概率是cmd程序。

C.删减定时任务观察程序状态

删除DMS、BMS定时任务后，观察1个小时，并未发现cmd异常，说明异常是由cmd程序处理java应用程序数据时引起的。

D.新增大量数据观察程序状态

有没有可能是过多的数据导致或加速了cmd异常？还原DMS、BMS定时任务通过F5不断发送login.do产生大量异常cmd窗口不断刷新，经过3次测试，发现大量数据并不会加速cmd异常。

E. 多轮测试观察程序状态

当cmd出现卡死后，接着重启进行下一次，经过6、7次测试，每次正常运行的5分钟内、10分钟内、30分钟内不等，结果都会卡死。

F. 调整cmd屏幕大小观察程序状态

调整屏幕缓冲区宽度和高度，与窗口大小保持一致屏幕宽=200、屏幕高=52，观察1个小时，并未出现cmd卡死情况

G. 调整cmd屏幕大小后多轮测试观察程序状态

调整后，共进行5,6次测试，每次运行时间1小时，并未发现异常。

H. 长时间运行观察程序状态

调整后，经过3天运行，cmd仍未卡死。自此判断cmd卡死又屏幕设置不当所致。

I. 复测2环境

首先，调整2环境与14环境一致：JVM也使用jdk 1.6,内存3G，现有应用如下

与14环境相比少了DMS、BMS， 新增DMS、BMS在2环境，同事吧程序中数据库执行14环境，保证定时任务产生的数据保持一致。

其次，在2环境上进行与14环境重复同样步骤BDEFG，并未出现卡死现象。

J. 测试cmd性能

D步骤中通过F5刷新后，经过3次测试并未发现问题，但不能完全覆盖cmd卡死时的情况，需要开发DEMO进行验证。

在第一个DEMO版本中，使用了单线程打印自定义异常，运行两天未发现问题（cmd屏幕宽高9999/9999 ）；第二个版本里，数据采用老产品日志数据，bms、dc、dms,分3个线程分别打印日志（cmd屏幕宽高9999/9999 ），如下图

在14上测试两次，不到两分钟卡死。再次缩小bms、dc日志使用dms-console.log-little、dc-console.log-little日志,运行两次，仍然出现卡死情况，调整屏幕宽高不会出现卡死；

在2上测试，使用dms-console.log-little、dc-console.log-little不会出现异常，当dms-console.log-little切换回dms-console.log，出现卡死情况，调整屏幕宽高不会出现卡死。

通过本次实验说明当单次数据量大、发送次数过多后，cmd程序存在一定的性能问题，且2的性能略高于14（与之前的测试结果一致）。

（四）最终结论

首先，cmd程序问题确实是由java程序发送了过多的数据特别是异常堆栈信息导致，因为异常堆栈数据量一般较大，并且cmd程序设置了不当屏幕宽高，导致控制台运行一段时间后卡死；

其次，从第三步“检查运行时堆栈情况”中发现DC、BMS、DMS定时任务线程都blocked在打印cmd控制台这块，打印cmd控制台是一个串行操作，也就是java应用程序中的所有线程都是排队打印cmd控制台的，当cmd出现性能问题时就会导致所有的线程等待，不管是定时任务线程还是web请求线程，web请求线程代表的是用户界面的操作，所以会出现页面缓慢、卡死的情况。所以应该做两方面的调整：第一，应用程序使用异步打印日志，也就是用专门的线程执行打印操作，这样不影响web请求线程阻塞；第二，减少或避免单次大日志输出到控制台，通常来说是异常日志，异常日志应该只输出到文件中。

（五）改进措施

首先，调整cmd屏幕大小，与窗口大小保持一致；

其次，修改应用（优先DC、BMS、DMS）对定时任务类异常只输出到日志文件中，不输出至控制台；

第三，修改应用（优先DC、BMS、DMS）改e.printStackTrace为log4j2输出；

第四，修改应用（优先DC、BMS、DMS）升级log4j为log4j2，使用log4j2异步机制；

第五，时常关注控制台异常，用以上三步方法调整。

次，修改应用（优先DC、BMS、DMS）对定时任务类异常只输出到日志文件中，不输出至控制台；

第三，修改应用（优先DC、BMS、DMS）改e.printStackTrace为log4j2输出；

第四，修改应用（优先DC、BMS、DMS）升级log4j为log4j2，使用log4j2异步机制；

第五，时常关注控制台异常，用以上三步方法调整。