我们代码从dev合到release的时候，会跑单元测试，检查单元测试覆盖率达到了50%才能合到release发布到uat环境
但是最近几个月，单元测试一直需要跑30-50分钟，才能跑完。
之前也有一次单元测试跑的时间过长，然后我删删改改从30分钟到了10分钟；
但是这次我们又有这样的问题了，很浪费时间，很影响工作效率。
我本地跑了一下单元测试，有了一个大发现。
我本地是windows，CPU会飙到100%，电脑也差不多卡死了。
image.png
前几天我就发现了这个现象了，也打算找找CPU100%的原因，因为我们单元测试已经写得蛮标准规范的了，把该mock的地方都mock掉了，里面没有啥特殊的代码的，而且跑单元测试的时候，应该是一个单元测试一个单元测试的跑的，根本不会这么消耗CPU。
直接从任务管理器中拿到PID，然后jstack到txt中
image.png
2021-05-07 20:40:21
Full thread dump OpenJDK 64-Bit Server VM (25.202-b08 mixed mode):
"qconfig-logger" #278 daemon prio=5 os_prio=0 tid=0x0000000028fc5000 nid=0x574 waiting on condition [0x000000004ec4e000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x000000073c5bd2f0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingDeque.takeFirst(LinkedBlockingDeque.java:492)
at java.util.concurrent.LinkedBlockingDeque.take(LinkedBlockingDeque.java:680)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
"FileWatcher-Thread" #277 daemon prio=5 os_prio=0 tid=0x0000000028fc6800 nid=0x65e4 waiting on condition [0x000000004e94e000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000740a8e430> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingDeque.takeFirst(LinkedBlockingDeque.java:492)
at java.util.concurrent.LinkedBlockingDeque.take(LinkedBlockingDeque.java:680)
at com.ctrip.framework.foundation.config.local.watchservice.AbstractWatchService.take(AbstractWatchService.java:114)
at com.ctrip.framework.foundation.config.local.file.RecursiveWatcher.take(RecursiveWatcher.java:54)
at com.ctrip.framework.foundation.config.local.file.FileEventDispatcher.run(FileEventDispatcher.java:32)
at java.lang.Thread.run(Thread.java:748)
"pool-101-thread-1" #276 prio=5 os_prio=0 tid=0x0000000028fc4800 nid=0x320 runnable [0x000000004e84e000]
java.lang.Thread.State: RUNNABLE
at java.io.WinNTFileSystem.getBooleanAttributes(Native Method)
at java.io.File.exists(File.java:819)
at com.ctrip.framework.foundation.config.local.watchservice.PollingWatchService$PollingWatchKey.poll(PollingWatchService.java:366)
- locked <0x0000000740f22998> (a com.ctrip.framework.foundation.config.local.watchservice.PollingWatchService$PollingWatchKey)
at com.ctrip.framework.foundation.config.local.watchservice.PollingWatchService$PollingWatchKey$1.run(PollingWatchService.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
"FileWatcher-Thread" #275 daemon prio=5 os_prio=0 tid=0x0000000028fc6000 nid=0x5f20 waiting on condition [0x000000004e74e000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000740a8e430> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingDeque.takeFirst(LinkedBlockingDeque.java:492)
at java.util.concurrent.LinkedBlockingDeque.take(LinkedBlockingDeque.java:680)
at com.ctrip.framework.foundation.config.local.watchservice.AbstractWatchService.take(AbstractWatchService.java:114)
at com.ctrip.framework.foundation.config.local.file.RecursiveWatcher.take(RecursiveWatcher.java:54)
at com.ctrip.framework.foundation.config.local.file.FileEventDispatcher.run(FileEventDispatcher.java:32)
at java.lang.Thread.run(Thread.java:748)
"pool-100-thread-1" #274 prio=5 os_prio=0 tid=0x0000000028fc7800 nid=0x5d6c runnable [0x000000004e64e000]
java.lang.Thread.State: RUNNABLE
at sun.nio.fs.WindowsNativeDispatcher.FindFirstFile0(Native Method)
at sun.nio.fs.WindowsNativeDispatcher.FindFirstFile(WindowsNativeDispatcher.java:185)
at sun.nio.fs.WindowsDirectoryStream.<init>(WindowsDirectoryStream.java:78)
at sun.nio.fs.WindowsFileSystemProvider.newDirectoryStream(WindowsFileSystemProvider.java:518)
at java.nio.file.Files.newDirectoryStream(Files.java:457)
at com.ctrip.framework.foundation.config.local.watchservice.PollingWatchService$PollingWatchKey.poll(PollingWatchService.java:303)
- locked <0x0000000740bbb530> (a com.ctrip.framework.foundation.config.local.watchservice.PollingWatchService$PollingWatchKey)
at com.ctrip.framework.foundation.config.local.watchservice.PollingWatchService$PollingWatchKey$1.run(PollingWatchService.java:264)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
"qconfig-worker-local-callback#-thread-1" #273 daemon prio=5 os_prio=0 tid=0x000000002adf5000 nid=0x2314 waiting on condition [0x000000004e54e000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x000000073e76e578> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
发现很多线程一直在跑，都在等锁啥的。
我又拿process explorer看了一下，N多的线程。
image.png
我就拿着jstack出来的内容找了框架组的同事，果然有问题。
跟框架同事研究了一下，他们说是他们有一个线程，会查看qconfig的文件变更，200微秒就会跑一次这个监听，而且这个逻辑只有在跑单元测试的这个环境会有：(。这个逻辑其实也没什么问题，后来发现了问题根本所在：
就是一个单元测试跑完后，这个监听的线程并没有结束掉，还会继续存在，继续查看文件变更。
这就导致了线程越跑越多，把cpu都卡死了。
用框架同事的话说，就是起了很多个在跑死循环的线程。电脑不卡才怪，单元测试不慢才怪呢。
找到问题了，就等框架同事把这个bug修复掉。
框架同事先把200微秒改成了1个小时，打了个包给我，我再跑了一次，直接起飞，我电脑上只用了4分钟不到，就把单元测试跑完了。
主要问题还是线程没有跟着单元测试结束掉导致的，这个他们还在排查，等下个版本修复了给到正式的包我们。
今天这个感觉很有成就感，我以前都没有真正的用到jstack解决过问题，今天这个jstack+process explorer，真是实战了一把，帮我们发现了一个大bug。虽然还没有用到jstack的高深用法，但是也发现了问题。
不过本来前几天就能发现这个的，当时不知道怎么就没有继续排查下去，做事情要专心，不能被打断。
