一次诡异的日志死锁

先说下项目背景，为了统一公司的schedule job，做了一个job的框架，定时任务统一接入到这个框架里面。

job框架用java开发，原理很简单，解析用户输入的crontab表达式，到了schedule的时间，用ProcessBuilder把用户的程序给带起来。

今天有同事反应，程序在本地可以正常运行，接入job框架后出现大量的SOA远程调用timeout。

第一反应是资源文件加载路径的问题，怀疑是不是读错了配置文件，再三检查发现一切无误。

打印线程堆栈后发现，所有的线程都卡死在了logback记日志的地方，大家都在等待一把锁，堆栈里面没能发现谁持有了这个锁对象。

从以下几点着手排查：

1. 怀疑是jar包冲突，job框架本身使用的logback版本和用户程序使用的logback版本冲突。于是一番折腾，无果。

2. 怀疑是SOA框架里面记日志的地方有冲突，再三check，还是无果。

然后发现用户的log配置，除了写磁盘以外，还会输出到console，于是改了下配置文件，不再输出到console，发现不再死锁。

于是赶紧的查了下jdk里面关于process的描述，摘录如下：

By default, the created subprocess does not have its own terminal or console. All its standard I/O (i.e. stdin, stdout, stderr) operations will be redirected to the parent process, where they can be accessed
via the streams obtained using the methods 

getOutputStream()

, 

getInputStream()

,
and 

getErrorStream()

.
The parent process uses these streams to feed input to and get output from the subprocess. Because some native platforms only provide limited buffer size for standard input and output streams, failure to promptly write the input stream or read the output stream
of the subprocess may cause the subprocess to block, or even deadlock.

子进程是没有自己的console的，标准输出会redirect给自己的父进程。子进程输出到操作系统的buffer里面，等待着父进程从inputstream里面读出数据，如果父进程没有读，那么一旦buffer满了，子进程就会处于waiting状态，等待buffer清空，造成死锁。

看了这段描述后，真相大白了，job框架不会去读用户输出到ocnsole的信息，从而导致了死锁。

解决方法后很简单，禁止用户输出到console，日志直接写磁盘。