记一次Runtime.getRuntime().exec(cmdarrayFinal)多线程使用synchronize连接mysql数据库，线程hung住的问题

 

记一次Runtime.getRuntime().exec(cmdarrayFinal)多线程使用synchronize连接mysql数据库，线程hung住的问题

 

先上截图：datax同步数据，自己改写了master分支加了数据同步加密，然后channel设置多线程有点多时，同步就hung住了

 

根据日志判断方法hung在哪个方法的调用以及本地debug，主要是debug让我最终判断出在获取数据库连接的时候hung住了

 

上面看这是个synchronized修饰的方法，hung住的原因应该是有个数据库连接没释放，导致了其他线程无法创建连接，一直等哪个线程释放数据库连接。

但是为什么没释放呢？出了什么故障导致的数据库连接没有释放了，也没有报错，没任何报错日志

 

我们用jsp -lm和jstack pid 来看看能否找到hung住的原因，解决我的问题。

这里有个博客还行，可以大概跟着看出来怎么排查问题但是有点简单了，对小白很友好：https://www.cnblogs.com/zhengyun_ustc/archive/2013/03/18/tda.html

 

然后找到我自己的jstack日志，可以看出0-0-28-writer线程和后面其他几个线程都阻塞了，被一个0x00000000c00663a8的给阻塞了，然后我们看下0x00000000c00663a8 这个在哪呢

 

 

然后我找到31这个线程持这个锁，其他线程都在等31线程释放，31是个runnable state线程然后一直往上找，最后发现竟然是因为mysql-connection jar包里面最后打印日志的方法里写了个system.error.println()方法导致的线程hung住。

一开始看到时觉得这不是扯吗？为啥system.error会hung住线程，另外这是mysql-connect jar包我怎么改啊，然后阴差阳错，我想为啥之前项目部署的不会有这个问题，想对比下mysql的版本，一看果然版本不同，替换了mysql版本结果运行就正常了。说明问题就出在mysql-connect jar包的代码

 

 

其实在这之前也对比了两个版本的mysql代码，但是对比的地方不对，没找出来不同，现在验证了就是mysqljar包导致的，我就仔仔细细就对比了每一步mysql-connect的代码有什么区别，最终找到原来现版本建立数据库连接比原来的多了这段代码，看到了没这段代码正是上面jstack里面报错的方法

 

然后我们看到原来jar包不同，升级了mysql5.7以上的连接参数，根据判断没有useSSL=true，就走到了setuseSSL=true，并打印了日志，而线程hung住就是因为打印了日志引起的。所以我要让连接数据库不走这段代码

 

所以解决办法：

1、替换mysql版本为旧的，或者整个项目的mysql版本都可以升级下

2、jdbcUrl设置参数，添加：useSSL=true&requireSSL=false&verifyServerCertificate=false

 

 

最后选择添加后缀就可以让线程正常并发，自测也没啥问题，解决了此问题。

这个后缀如果不加就会线程阻塞：jdbc:mysql://10.9.45.207:3306/mll_0?useSSL=true&requireSSL=false&verifyServerCertificate=false

 

最后为什么syste.err.println()会导致多线程hung住呢？我来找找，找到了为什么system.err.println()为什么导致线程阻塞了。

我还是不明白为什么system.err.println为什么会导致线程阻塞，那是不是意味着我在别的地方经常打印err也会导致线程阻塞，所以上面的解决方案治标不治本。

于是我自己本地直接启动engine的main方法发现哎？服务正常启动，同步正常，数据正常。

然后直接本地控制台执行python C:user/.../datax.py C:user/.../job.json 执行完服务启动成功，同步正常

说明什么只有代码执行runtime.getruntime.exec()方法才导致子进程阻塞

然后百度看了下，说是子进程执行过程中会不断向jvm进行标准输出和标准错误输出都会输出到父进程中，java通过process提供的getoutputstream和getinputstream和geterrorputstream来获取子进程的输入输出信息。因为输入输出缓冲区大小有限，当标准输出和标准错误输出写满缓存池，程序会无法写入，子进程无法正常退出。读写子进程的输出流或输入流失败，则可能导致子进程阻塞甚至产生死锁。所以主进程需要用两个线程去读取子进程的inputstream和errorputstream。

具体看：https://www.jianshu.com/p/f44ebc263e62

而我们代码出现了什么呢？

 

先获取标准输出流的结果，然后再启动读取错误输出流，这时错误输出流超过了缓存池，一直没有清空，则获取数据库连接会一直没法退出，其他线程一直等着获取数据库连接，所以futureTask.get()一直阻塞，就一直没法errThread.start 去读取错误流没法清空缓存池，没法清空缓存池，数据库连接就一直没法退出一直等，结果就子进程就阻塞了。上面截图最后的红框在有错误流且占满缓存池的情况下会导致死锁。

所以要先将errthread.start方法放前面，让主进程一直读取错误流，这样就不会阻塞子进程了。

 

所以需要将代码换下位置改为：

最终完美解决，也搞清楚因果。

 

 

经此一游，自己很喜欢写system日志，注意不要随便在项目里面打印system.err或者out日志，多线程会出问题！！！

因为我们平时很Low，都是单线程，所以没出过问题，不带代表没有问题！！

 

总结整个过程：

先看日志找到在哪调用，哪块不走了，本地debug发现线程hung在数据库连接，看了代码发现获取数据库连接用synchronize修饰，说明，剩下的数据库连接都在等没释放的那个数据库连接，然后为啥会没释放呢，代码也没报错，看了半天看不出来。

然后想到用jsp -lm查看正在运行的进程，然后jstack pid查看报错，找到原来broke什么堵塞了，都在等writer方法的数据库连接，报错是因为println()日志导致的，你说扯不扯

然后我想为啥之前的数据库连接不报这个错，线程不会hung住，我看看之前的mysql-connectionjar包是什么版本，一看，和我现在的jar包版本不一样啊，那我直接替换掉mysql-connection的jar包为之前的呢，测试下，果然，没有出现线程hung住的问题了。说明啥呢还是mysql-connection的jar包里的代码有问题，然后找到mysql-connect包具体哪个代码引起的，升级后的mysql-connection jar包连数据库多了一个这个方法，因为jdbcurl没有设置usessl就走了方法里面，然后就打印了logWarn，然后他的log里面写了个systerm.err.prlintln()方法，最终就导致缓存池满了。system.err.prinltn会导致缓存池满了？具体的为啥需要再深入，深入过程已在上面说明了，这个是重点不重复了。

 

最终定位是Runtime.getRuntime().exec(cmdarrayFinal)错误输出流代码的问题，导致的死锁。

 

 

总结：看别人的代码需要先看一遍代码，对自己没用过的方法原理做一个了解，然后再开始开发或者排查bug。学习很重要。