摘要：原文在容器打印日志到控制臺(tái)阻塞的排障的時(shí)候看到一個(gè)觀點(diǎn)把日志打印到控制臺(tái)要比打印到文件慢，而且是非常慢。那么為何輸出到控制臺(tái)慢有何辦法加速呢問(wèn)題要從三個(gè)角度來(lái)分別回答的角度程序角度容器角度角度寫到控制臺(tái)其實(shí)就是寫到，更嚴(yán)格的說(shuō)應(yīng)該是。

原文

在容器打印日志到控制臺(tái)阻塞的排障的時(shí)候看到一個(gè)觀點(diǎn)：

把日志打印到控制臺(tái)要比打印到文件慢，而且是非常慢。

log4j2和logback的兩個(gè)issue官方也提到了這一點(diǎn)（見(jiàn)LOG4J2-2239、LOGBACK-1422）。

那么為何輸出到控制臺(tái)慢？有何辦法加速呢？問(wèn)題要從三個(gè)角度來(lái)分別回答：

linux的stdout角度

Java程序角度

docker容器角度

寫到控制臺(tái)其實(shí)就是寫到stdout，更嚴(yán)格的說(shuō)應(yīng)該是fd/1。Linux操作系統(tǒng)將fd/0、fd/1和fd/2分別對(duì)應(yīng)stdin、stdout和stdout。

那么問(wèn)題就變成為何寫到stdout慢，有何優(yōu)化辦法？

造成stdout慢的原因有兩個(gè)：

你使用的終端會(huì)拖累stdout的輸出效率

stdout的緩沖機(jī)制

在SO的這個(gè)問(wèn)題中：Why is printing to stdout so slow? Can it be sped up?，這回答提到打印到stdout慢是因?yàn)榻K端的關(guān)系，換一個(gè)快速的終端就能提升。這解釋了第一個(gè)原因。

stdout本身的緩沖機(jī)制是怎樣的？Stdout Buffering介紹了glibc對(duì)于stdout緩沖的做法：

當(dāng)stdout指向的是終端的時(shí)候，那么它的緩沖行為是line-buffered，意思是如果緩沖滿了或者遇到了newline字符，那么就flush。

當(dāng)stdout沒(méi)有指向終端的時(shí)候，那么它的緩沖行為是fully-buffered，意思是只有當(dāng)緩沖滿了的時(shí)候，才會(huì)flush。

其中緩沖區(qū)大小是4k。下面是一個(gè)總結(jié)的表格“
GNU libc (glibc) uses the following rules for buffering”:

那也就是說(shuō)當(dāng)stdout指向一個(gè)終端的時(shí)候，它采用的是line-buffered策略，而終端的處理速度直接影響到了性能。

同時(shí)也給了我們另一個(gè)思路，不將stdout指向終端，那么就能夠用到fully-buffered，比起line-buffered能夠帶來(lái)更大提速效果（想想極端情況下每行只有一個(gè)字符）。

我寫了一段小代碼來(lái)做測(cè)試（gist）。先試一下stdout指向終端的情況：

$ javac ConsolePrint.java
$ java ConsolePrint 100000
...
lines: 100,000
System.out.println: 1,270 ms
file: 72 ms
/dev/stdout: 1,153 ms

代碼測(cè)試了三種用法：

System.out.println 指的是使用System.out.println所花費(fèi)的時(shí)間

file 指的是用4k BufferedOutputStream 寫到一個(gè)文件所花費(fèi)的時(shí)間

/dev/stdout 則是同樣適用4k BufferedOutputStream 直接寫到/dev/stdout所花費(fèi)的時(shí)間

發(fā)現(xiàn)寫到文件花費(fèi)速度最快，用System.out.println和寫到/dev/stdout所花時(shí)間在一個(gè)數(shù)量級(jí)上。

如果我們將輸出重定向到文件：

$ java ConsolePrint 100000 > a
$ tail -n 5 a
...
System.out.println: 920 ms
file: 76 ms
/dev/stdout: 31 ms

則會(huì)發(fā)現(xiàn)/dev/stdout速度提升到file一個(gè)檔次，而System.out.println并沒(méi)有提升多少。之前不是說(shuō)stdout不指向終端能夠帶來(lái)性能提升嗎，為何System.out.println沒(méi)有變化呢？這就要Java對(duì)于System.out的實(shí)現(xiàn)說(shuō)起了。

下面是System的源碼：

public final static PrintStream out = null;
...
private static void initializeSystemClass() {
  FileOutputStream fdOut = new FileOutputStream(FileDescriptor.out);
  setOut0(newPrintStream(fdOut, props.getProperty("sun.stdout.encoding")));
}
...
private static native void setOut0(PrintStream out);
...
private static PrintStream newPrintStream(FileOutputStream fos, String enc) {
  ...
  return new PrintStream(new BufferedOutputStream(fos, 128), true);
}

可以看到System.out是PrintStream類型，下面是PrintStream的源碼：

private void write(String s) {
  try {
    synchronized (this) {
      ensureOpen();
      textOut.write(s);
      textOut.flushBuffer();
      charOut.flushBuffer();
      if (autoFlush && (s.indexOf("
") >= 0))
        out.flush();
    }
  } catch (InterruptedIOException x) {
    Thread.currentThread().interrupt();
  } catch (IOException x) {
    trouble = true;
  }
}

可以看到：

System.out使用的緩沖大小僅為128字節(jié)。大部分情況下夠用。

System.out開(kāi)啟了autoFlush，即每次write都會(huì)立即flush。這保證了輸出的及時(shí)性。

PrintStream的所有方法加了同步塊。這避免了多線程打印內(nèi)容重疊的問(wèn)題。

PrintStream如果遇到了newline符，也會(huì)立即flush（相當(dāng)于line-buffered）。同樣保證了輸出的及時(shí)性。

這解釋了為何System.out慢的原因，同時(shí)也告訴了我們就算把System.out包到BufferedOutputStream里也不會(huì)有性能提升。

那么把測(cè)試代碼放到Docker容器內(nèi)運(yùn)行會(huì)怎樣呢？把gist里的Dockerfile和ConsolePrint.java放到同一個(gè)目錄里然后這樣運(yùn)行：

$ docker build -t console-print .
$ docker run -d --name console-print console-print 100000
$ docker logs --tail 5 console-print
...
lines: 100,000
System.out.println: 2,563 ms
file: 27 ms
/dev/stdout: 2,685 ms

可以發(fā)現(xiàn)System.out.println和/dev/stdout的速度又變回一樣慢了。因此可以懷疑stdout使用的是line-buffered模式。

為何容器內(nèi)的stdout不使用fully-buffered模式呢？下面是我的兩個(gè)猜測(cè):

不論你是docker run -t分配tty啟動(dòng)，還是docker run -d不非配tty啟動(dòng)，docker都會(huì)給容器內(nèi)的stdout分配一個(gè)tty。

因?yàn)閐ocker的logging driver都是以“行”為單位收集日志的，那么這個(gè)tty必須是line-buffered。

雖然System.out.println很慢，但是其吞吐量也能夠達(dá)到~40,000 lines/sec，對(duì)于大多數(shù)程序來(lái)說(shuō)這不會(huì)造成瓶頸。

Standard output (stdout)

Stdout Buffering