摘要:原文在容器打印日志到控制臺阻塞的排障的時候看到一個觀點把日志打印到控制臺要比打印到文件慢,而且是非常慢。那么為何輸出到控制臺慢有何辦法加速呢問題要從三個角度來分別回答的角度程序角度容器角度角度寫到控制臺其實就是寫到,更嚴格的說應該是。
原文
在容器打印日志到控制臺阻塞的排障的時候看到一個觀點:
把日志打印到控制臺要比打印到文件慢,而且是非常慢。
log4j2和logback的兩個issue官方也提到了這一點(見LOG4J2-2239、LOGBACK-1422)。
那么為何輸出到控制臺慢?有何辦法加速呢?問題要從三個角度來分別回答:
linux的stdout角度
Java程序角度
docker容器角度
stdout角度寫到控制臺其實就是寫到stdout,更嚴格的說應該是fd/1。Linux操作系統將fd/0、fd/1和fd/2分別對應stdin、stdout和stdout。
那么問題就變成為何寫到stdout慢,有何優化辦法?
造成stdout慢的原因有兩個:
你使用的終端會拖累stdout的輸出效率
stdout的緩沖機制
在SO的這個問題中:Why is printing to stdout so slow? Can it be sped up?,這回答提到打印到stdout慢是因為終端的關系,換一個快速的終端就能提升。這解釋了第一個原因。
stdout本身的緩沖機制是怎樣的?Stdout Buffering介紹了glibc對于stdout緩沖的做法:
當stdout指向的是終端的時候,那么它的緩沖行為是line-buffered,意思是如果緩沖滿了或者遇到了newline字符,那么就flush。
當stdout沒有指向終端的時候,那么它的緩沖行為是fully-buffered,意思是只有當緩沖滿了的時候,才會flush。
其中緩沖區大小是4k。下面是一個總結的表格“
GNU libc (glibc) uses the following rules for buffering”:
Stream | Type | Behavior |
---|---|---|
stdin | input | line-buffered |
stdout (TTY) | output | line-buffered |
stdout (not a TTY) | output | fully-buffered |
stderr | output | unbuffered |
那也就是說當stdout指向一個終端的時候,它采用的是line-buffered策略,而終端的處理速度直接影響到了性能。
同時也給了我們另一個思路,不將stdout指向終端,那么就能夠用到fully-buffered,比起line-buffered能夠帶來更大提速效果(想想極端情況下每行只有一個字符)。
我寫了一段小代碼來做測試(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
代碼測試了三種用法:
System.out.println 指的是使用System.out.println所花費的時間
file 指的是用4k BufferedOutputStream 寫到一個文件所花費的時間
/dev/stdout 則是同樣適用4k BufferedOutputStream 直接寫到/dev/stdout所花費的時間
發現寫到文件花費速度最快,用System.out.println和寫到/dev/stdout所花時間在一個數量級上。
如果我們將輸出重定向到文件:
$ java ConsolePrint 100000 > a $ tail -n 5 a ... System.out.println: 920 ms file: 76 ms /dev/stdout: 31 ms
則會發現/dev/stdout速度提升到file一個檔次,而System.out.println并沒有提升多少。之前不是說stdout不指向終端能夠帶來性能提升嗎,為何System.out.println沒有變化呢?這就要Java對于System.out的實現說起了。
Java程序角度下面是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字節。大部分情況下夠用。
System.out開啟了autoFlush,即每次write都會立即flush。這保證了輸出的及時性。
PrintStream的所有方法加了同步塊。這避免了多線程打印內容重疊的問題。
PrintStream如果遇到了newline符,也會立即flush(相當于line-buffered)。同樣保證了輸出的及時性。
這解釋了為何System.out慢的原因,同時也告訴了我們就算把System.out包到BufferedOutputStream里也不會有性能提升。
Docker容器角度那么把測試代碼放到Docker容器內運行會怎樣呢?把gist里的Dockerfile和ConsolePrint.java放到同一個目錄里然后這樣運行:
$ 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
可以發現System.out.println和/dev/stdout的速度又變回一樣慢了。因此可以懷疑stdout使用的是line-buffered模式。
為何容器內的stdout不使用fully-buffered模式呢?下面是我的兩個猜測:
不論你是docker run -t分配tty啟動,還是docker run -d不非配tty啟動,docker都會給容器內的stdout分配一個tty。
因為docker的logging driver都是以“行”為單位收集日志的,那么這個tty必須是line-buffered。
雖然System.out.println很慢,但是其吞吐量也能夠達到~40,000 lines/sec,對于大多數程序來說這不會造成瓶頸。
參考文檔Standard output (stdout)
Stdout Buffering
文章版權歸作者所有,未經允許請勿轉載,若此文章存在違規行為,您可以聯系管理員刪除。
轉載請注明本文地址:http://specialneedsforspecialkids.com/yun/27696.html
摘要:原文在容器打印日志到控制臺阻塞的排障的時候看到一個觀點把日志打印到控制臺要比打印到文件慢,而且是非常慢。那么為何輸出到控制臺慢有何辦法加速呢問題要從三個角度來分別回答的角度程序角度容器角度角度寫到控制臺其實就是寫到,更嚴格的說應該是。 原文 在容器打印日志到控制臺阻塞的排障的時候看到一個觀點: 把日志打印到控制臺要比打印到文件慢,而且是非常慢。 log4j2和logback的兩個iss...
摘要:是指可能導致程序終止的非常嚴重的時間。具有最高的級別,旨在關閉中的日志功能。因此為每一個消息選擇一個合適的日志級別是非常重要的。日志的個小建議將日志訪日代碼塊它能顯著的減少因為字符串拼接而帶來的性能的影響。 前言 首先,這篇文章沒有進行任何的日志功能的詳細介紹,而是對日志提出了幾種最佳實踐。適合對日志記錄有所了解的同學閱讀。下面是正文: JAVA日志管理既是一門科學,又是一門藝術。科學...
摘要:為何選擇引擎微信小游戲推出之后,很多公司也相應的進入到微信小游戲這個領域,現在市場上的游戲開發引擎,如都對小游戲有了很好的兼容性。 1. 為何選擇Laya引擎 微信小游戲推出之后,很多公司也相應的進入到微信小游戲這個領域,現在市場上的游戲開發引擎,如Cocos、Egret、Laya都對小游戲有了很好的兼容性。目前公司技術棧主要是使用Cocos和Laya,經過幾個項目的接觸,考量了引擎在...
閱讀 922·2021-10-13 09:48
閱讀 3907·2021-09-22 10:53
閱讀 3114·2021-08-30 09:41
閱讀 1943·2019-08-30 15:55
閱讀 2920·2019-08-30 15:55
閱讀 1839·2019-08-30 14:11
閱讀 2205·2019-08-29 13:44
閱讀 764·2019-08-26 12:23