背景
我所在项目组是做Wifi数据传输业务的工作,简单来说,公司的wifi设备铺设到各个城市的店铺中,这些设备产生的数据会实时上传至云,而我们项目组的工作就是将各个平台管辖区域的数据传输给各平台。每个平台的数据格式、传输方式都可能是不同的,传输方式大部分以FTP为主,以及传输时间间隔大部分是每5分钟传输一次。那一天早上一个平台的客户打电话过来反馈说我们传输的数据在凌晨就断掉了,于是就有了这一次线上Debug的过程。
Debug过程
首先猜测的是该平台所在服务器的服务Down掉了,于是进入该服务器,发现Java进程依然生龙活虎,又看了下阿里云的监控,在停止传输的那段时间内Cpu、内存等指标并没有明显的异常,排除服务Down掉的原因。接着我去看了下传输的日志,确实传输的日志从凌晨开始就没有再产生,不仅仅是该平台,所有该服务器传输的平台数据传输任务都停止了。眉头一蹙,感觉事情并不简单。
系统在发送数据前,会先生成数据文件并保留一段时间,于是查看了下生成文件的情况,文件依然在正常地每5分钟生成一次。由此可知生成数据的流程是没有问题的,那么问题的范围可以进一步被缩小,猜测是发送线程池有异常导致停止发送。
带着猜想,使用jstack查看传输线程池中所有线程的状态,如下图:
这个传输线程池由固定20个线程组成,其中19个线程的状态如图一所示——阻塞等待0x00000006a6271680
这个锁,另外一个线层状态如图二所示——获得0x00000006a6271680
锁,并一直在socketRead0
上挂起。有一点需要补充的是线程状态RUNNABLE既可表示线程正常运行也可表示线程正在等待系统资源而挂起,此时是第二种情况。现在bug的原因基本已经找到:某一持有锁的线程因为某种原因一直在socketRead0
挂起,而其他线程都在排队等待该锁最终导致了整个传输线程池的线程不可用,也就无法传输数据了。
探寻bug发生原因
现在Bug大致原因已经明晰,但是实质性的为什么线程会在socketRead0
上挂起还需要进一步去了解原因。首先针对我们的业务解释下为什么会出现锁争用的情况。
为何发生锁争用
每个平台对应了一个FTPTransfer
对象用来给对方平台传输数据,传输线程池大致每隔5分钟会被调度运行一次,FTPTransfer
中发送数据方法sendData
是加锁的,方法结构如下:
public synchronized void sendData(final File file) throws IOException {
//发送逻辑
}
在一般情况下,每个平台用各自的FTPTransfer
发送数据是不会出现锁争用的情况的,但是现在出现了一个平台A,线程在给A发送数据时挂起并且一直占用着A对应的FTPTransfer
锁,此时其他线程正常给其他平台传输数据,下一个5分钟后其余的某个线程再次想给平台A发送数据而阻塞自己等待挂起线程释放锁。在n个5分钟后其余所有线程都在等待该挂起线程释放锁,最终出现整个线程池不可用的情况。
socketRead0
这里通过一篇博客的引用来解释下socketRead0
这个本地方法是做什么的。
What does SocketInputStream.socketRead0() API do?
It’s always easy to remember new concepts through real life analogies. Say suppose you are calling your wife or girlfriend on the phone. Once call gets connected, if she is in happy/good mood immediately you will get response “Hello Honey (or darling or sweetie), How are you?” If your call got connected when she is in middle of doing some work (say she is in her office, picking up kids, Gym…) there might be delay in her response to say “Hello Honey (or darling or sweetie) ….”. Suppose your call got connected when she is in angry/bad mood then response can be unpredictable. God only knows. You might get response after several seconds/minutes (or even call can get hanged up . So, the time you are waiting since the moment call got connected until the moment you hang-up the call is basically socketRead0() API. (Thanks to Douglas Spath from IBM for giving this beautiful example to explain this SocketRead0() API.)
简单来说,对于FTP,当对方FTP服务器繁忙时,就可能出现socket延时响应或者一直挂起的情况。
Bug解决
那么如何解决socketRead0
一直挂起的情况呢?最常见的方法就是设置socket的超时时间setSoTimeout
,我们FTP工具类使用的是apache的commons-net,其中在生成FTPClient时也都设置了socket的超时时间,没有理由会一直出现socket一直挂起的情况。
在一番google下终于找到了答案,居然是Jdk的bug,bug的标题:SocketInputStream.socketRead0 can hang even with soTimeout set,bug号码:8075484,bug详情页。最终通过将环境的jdk版本升级到解决掉bug的版本,再没有出现同样的情况,成功解决数据不传输问题。