一次问题查找经历

前两天我们上线前预览的时候，预览结果等了好久好久好久都不出来，初步检查以为是错误用例太多导致重试耗时太长，可是第二天我还是没有收到结果邮件，这就有点儿说不过去了，所以开始查找原因

1，ps aux|grep java 发现前一天执行的测试进程都还在，这肯定是某个用例卡死了(很自信)

root     29715  8.4  2.8 31366700 2782652 ?    Sl   17:45   1:22 java -Djava.ext.dirs=/data1/WeTest/lib -classpath /data1/WeTest/runTmp/21f4edbe-2d11-451b-bfaf-f2f274b5849c/target/test-classes/ com.weibo.runfail.RunFailedCasesForServer TEST-com.weibo.cases.suite.UserGraphTestSuite.txt

以其中一个进程为例，查看他的堆栈信息: jstack -l 29715

除了刷的一堆跟数据库有关的其他的看不出什么东西来

"MySQL Statement Cancellation Timer" #69 daemon prio=5 os_prio=0 tid=0x00007fbe7c058800 nid=0x7462 in Object.wait() [0x00007fbf659b3000]

   java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

- waiting on <0x00000001dcf40d68> (a java.util.TaskQueue)

at java.lang.Object.wait(Object.java:502)

at java.util.TimerThread.mainLoop(Timer.java:526)

- locked <0x00000001dcf40d68> (a java.util.TaskQueue)

at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

- None

"C3P0PooledConnectionPoolManager[identityToken->z8kflt9vbsybuj1wcjaz|5556f23b]-HelperThread-#5" #68 daemon prio=5 os_prio=0 tid=0x00007fbef808a800 nid=0x7461 in Object.wait() [0x00007fbf65cb4000]

   java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683)

- locked <0x00000001dcf8ea88> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner)

   Locked ownable synchronizers:

- None

"C3P0PooledConnectionPoolManager[identityToken->z8kflt9vbsybuj1wcjaz|5556f23b]-HelperThread-#4" #67 daemon prio=5 os_prio=0 tid=0x00007fbef8088800 nid=0x7460 in Object.wait() [0x00007fbf65db5000]

   java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683)

- locked <0x00000001dcf8ea88> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner)

   Locked ownable synchronizers:

- None

"C3P0PooledConnectionPoolManager[identityToken->z8kflt9vbsybuj1wcjaz|5556f23b]-AdminTaskTimer" #62 daemon prio=5 os_prio=0 tid=0x00007fbef8070800 nid=0x745b in Object.wait() [0x00007fbf662ba000]

   java.lang.Thread.State: TIMED_WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

at java.util.TimerThread.mainLoop(Timer.java:552)

- locked <0x00000001dcf8f768> (a java.util.TaskQueue)

at java.util.TimerThread.run(Timer.java:505)

   Locked ownable synchronizers:

- None

显然(百度了好久)，很有可能是用了Timer的缘故，去代码里搜用到Timer的地方，果然，代码里有一个定时更新object表的地方，然饿，我们的库里已经没有这个表了，果断把没用的代码删掉，很开心，以为问题就此解决。

执行用例，还是一直没有收到结果邮件，这时候就体现了日志的重要性，耐心的看脚本执行流程，发现用例是执行完了的，只不过在第一次重试完成以后进程没有结束，无法进行第二次重试，那么为什么可以进行第一次重试，而第一次重试完又不会停呢？

这是因为在我的前端用例里调用了rpc方法，如果是从main函数进入调用的话，结束后rpc服务不会停止。这也是为什么最开始用例执行完可以直接进行第一次重试，而第一次重试完后不能进行第二次重试，因为重试代码的入口是main函数。

解决方法：

一、既然重试完后rpc服务还在导致java进程不结束那我就强制结束，在main函数的最后，所有用例都重试完之后，加一个system.exit()

改完以后运行脚本，最后收到了结果邮件，开心，但是没有开心很久，因为我发现对调用了rpc方法的用例日志里没有记录，所以我就不知道是执行成功了没有写到日志里去，还是压根就没执行。显然这种方法不是很适合。。。头疼，虽然我只写了这些内容，但是这个实际操作过程是很长的

二、把rpc方法部署成一个服务

把rpc方法部署成一个服务，不同的方法对应不同的接口实现，直接调接口，完美解决了上面的问题