首页 > 代码库 > 记一次诡异的调优

记一次诡异的调优

2024-07-10 18:11:54   229人阅读

最近碰到的一个Java应用，费了半天劲还是没定位到是哪儿的问。发上来给大家看看，给点建议。

 

环境

 

  • DB Server：32core HPUX DB2
  • App Server * 2：8core HPUX WAS6.1 每个节点2个app
初次测试现象
  • WAS，DB2CPU均上不去，CPU、内存、磁盘、网络等都正常。
  • 从loadrunner报告来看，有两个用例很奇怪，在16/24/50用户下，呈线性增长。根据经验，这两个用例可能存在资源争用，造成串行的地方。
  • 检查DB2，正常，语句执行都很快，部分用例有锁，但与造成问题的两个用例无关。
 
 
第一次尝试：初步定位是WAS的问题，针对WAS进行排查。
  • 关闭WAS应用打印的日志（据观察有System.out），刚开始有往外打印东西，量不大，但是很频繁，一秒钟大概几十条，无效。
  • 调整WAS监控日志为error，避免过多信息。无效。
  • 后减少用户数，使用1个用户长时间跑，发现那两个用例依旧随时间线性增长。说明问题不是因为资源争用，更可能是程序问题。
  • 检查WAS中的Apache，配置正常，返回页正常。
 
第二次尝试：定位应用程序哪块的问题
  • 因为WAS跑在HPUX上，使用HPjmeter跟踪线程状态，发现线程在IO上等待事件非常高。而程序占用IO最多的地方就是数据库连接。
  • 打印线程堆栈，发现大部分线程阻塞在SocketRead上。证明了HPjmeter IO占用高。
  • SokcetRead阻塞，可能以下几个地方有问题：数据库（很值得怀疑，但从数据库监控看，没有问题），网络（内网环境，这个应该也不会有问题），操作系统IO部分。
第三次尝试：针对SocketRead定位问题
  • 更新WAS所带JDK，无效。（JDK OK）
  • 更新操作系统IO部分最新Patch，无效。（OS IO OK）
  • 更新WAS的JDBC驱动，无效。（JDBC OK）
  • 把WAS和DB放在同一台机器上，无效。（网络 OK）
  • 通过WAS监控，其中JDBC Time很短（间接也说明了数据库正常），但是UseTime很高（是JDBC Time的100倍+）。
  • 程序除了这两个用例外，其他用例均正常。
悬而未决：问题到这，进了死胡同了。也没有更好的想法。
  • Use Time、JDBC Time、SocketRead的矛盾。
    • JDBC Time=JDBC处理时间+网络时间+数据库处理时间。JDBC Time应该包括了JDBC的SocketRead的时间。但是JDBC Time很小，而程序阻塞在SocketRead上。
    • Use Time=连接分配到连接归还的时间差=n*JDBC Time（在整个连接分配到归还之间的所有JDBC请求）+业务逻辑处理时间。
    • Use Time与JDBC Time差距很大，而且JDBC Time很小，能解释的话，第一种原因，就是在整个UseTime中有大量的JDBC请求，但是从这个业务看，不会有100倍那么多。
    • 第二种原因，是“业务逻辑程序处理时间”占用了很多。这个是有可能的，而且程序编写的bug也能说明为什么在1个用户的时候，用例执行时间也程序线性。但是，程序最耗时的地方出现在JDBC的SocketRead上，而JDBC Time又未反应出这部分的时间。
  • 什么造成了SocketRead阻塞
    • 这个问题一直没有弄清楚，在数据、网络都正常的话，Socket不应该阻塞
  • WAS的Java堆调整。这个问题是在调整WAS时碰到的。
    • WAS个人不是太熟，但是从一般JVM调整来说，基本是类似的，但是这次在WAS上碰到的问题也很诡异。
    • WAS堆之前配置是1560m，当调整为2048m后，用例的执行时间时间反而变长了。WAS堆之前配置是1560m，当调整为1024m后，用例的执行时间时间也变长了。很神奇的问题，程序执行速度一般取决于CPU和IO，内存影响很小，特别当内存足够的情况下。即便内存有影响，两个不同方向的调整居然能得出同样的结果，很令人费解。
    • 不知道是否有WAS方面的大牛给点提示：）
结论
  • 应用应该是有问题的，但是更细的东西或许只有看到代码才知道
  • WAS真不会用...


联系
我们