由於線上服務端程式，需要大量寫入日誌，將來入資料庫庫，以便做資料分析或者對賬之用，可是發現日誌開啟後伺服器變慢了，對外併發響應數量也減少了。於是分析了下日誌寫入函式fprintf。其寫日誌檔案的順序是：程式寫入使用者地址空間核心從使用者地址空間緩衝區複製到核心檔案緩衝區核心檔案緩衝區滿的情況下再放入核心io佇列，等待寫入到硬碟上。寫檔案其實不是直接寫到硬碟，那樣的話一堆程式都同時併發往硬碟上寫，硬碟能累吐血。所以檔案其實是先寫到記憶體，滿員後再寫到硬碟，當然這是核心完成的，我們使用者程式只要使用系統呼叫就行了。這樣可以減少寫硬碟的次數，一次批量多寫些內容進去。
一個程式使用系統呼叫的次數會很大程度上影響系統的效能,因為在執行系統時，會從使用者程式碼切換執行核心程式碼，然後返回使用者程式碼。優化手段就是儘量減少系統呼叫次數。

以上這種快取的思想是很OK的，那麼我們的問題在哪裡呢？我們的問題其實就是一次性寫入的日誌很大，通常會超過系統預設的使用者地址空間檔案緩衝區大小4096位元組，剛好就是一個頁的大小，應該是為了方便拷貝到核心而設的單位，我們往往一行日誌就寫了5000多位元組，有的甚至1M位元組。所以每次寫一行日誌都會觸發系統呼叫。而我們的伺服器程式寫日誌很頻繁，每秒都有幾次寫這種大型日誌的操作，寫小日誌的操作就更多了。當然可以分不同的檔案寫到多個日誌檔案中，緩解單個檔案緩衝區的壓力，不過這好像麼有治本。
在伺服器設計上的思想，我是儘可能的用空間換時間，因為使用者很挑剔啊，時間上人家可不願意多等幾秒。當然不要無限制的濫用空間，記憶體和硬碟也很寶貴的。
我們的辦法就是在寫日誌檔案的時候，使用setvbuf函式設定自己的緩衝區，儘量在記憶體夠用的情況下，設定大些。我設定了10*4096個位元組，這樣fprintf函式內部使用系統呼叫的頻率就少了，減少了不少次從使用者態拷貝小資料到核心態轉換的時間開銷，轉為積累大資料，一次性拷貝，只一次系統呼叫就搞定。接下來看示例

調大緩衝區

/**
 * test1.c
 * gcc test1.c -o test1
 */
#include <stdio.h>
#include <sys/stat.h>
#include <sys/time.h> 

#define BUF_SIZE 40960
#define LOOP_CNT 1000000

int main () 
{
    int i = 0;
    struct timeval start, end; // 計時用的結構
    float timeuse; // 耗時，s為單位

    char test_fmt[4108];
    for
 
(i = 0; i < 4108; i++){
        test_fmt[i] = 'A';
    } // 總共4108位元組。

    printf("迴圈%d條，資料總量%ld：\n", LOOP_CNT, (long)LOOP_CNT* 4108);

    FILE *pFile;
    struct stat sysbuf;
    stat("1.txt", &sysbuf);
    printf("系統預設檔案緩衝區大小 = %d byte,總共%d塊\n", (int)sysbuf.st_blksize, (int)sysbuf.st_blocks);
    pFile=fopen ("1.txt","w");
    gettimeofday(&start,NULL); // 開始計時
    for (i = 0; i < LOOP_CNT; i++){
        fprintf(pFile, test_fmt, i); // 每行128個A，總共4096個A，再加上末尾不到10個位元組的i和換行。
    }
    fclose (pFile);
    gettimeofday(&end,NULL); // 結束計時
    // 計算耗時
    timeuse = 1000000*(end.tv_sec - start.tv_sec) + end.tv_usec - start.tv_usec; 
    timeuse /= 1000000; 
    printf("預設緩衝區寫檔案，用時:%f\n", timeuse);

    return 0;
}

/**
 * test2.c
 * gcc test2.c -o test2
 */
#include <stdio.h>
#include <sys/stat.h>
#include <sys/time.h> 

#define BUF_SIZE 40960
#define LOOP_CNT 1000000

int main () 
{
    int i = 0;
    struct timeval start, end; // 計時用的結構
    float timeuse; // 耗時，s為單位

    char test_fmt[4108];
    for(i = 0; i < 4108; i++){
        test_fmt[i] = 'A';
    } // 總共4108位元組。

    printf("迴圈%d條，資料總量%ld：\n", LOOP_CNT, (long)LOOP_CNT* 4108);

    FILE *pFile1;
    pFile1=fopen ("2.txt","w"); 
    char buf[BUF_SIZE];
    setvbuf ( pFile1 , buf, _IOFBF , BUF_SIZE );
    printf("自定義緩衝區 = %d byte\n", BUF_SIZE);
    gettimeofday(&start,NULL); // 開始計時
    for (i = 0; i < LOOP_CNT; i++){
        fprintf(pFile1, test_fmt, i);
    }
    fclose (pFile1);
    gettimeofday(&end,NULL); // 結束計時
    // 計算耗時
    timeuse = 1000000*(end.tv_sec - start.tv_sec) + end.tv_usec - start.tv_usec; 
    timeuse /= 1000000; 
    printf("自定義緩衝區寫檔案，用時:%f\n", timeuse);

    return 0;
}

在一個5400轉硬碟的虛擬機器上，分別編譯執行，檢視結果，其中st_blocks代表該檔案使用了多少個塊。
一開始測試我犯了個嚴重的錯誤，就是將兩段程式碼編譯好的程式一起執行，或者兩次執行間隔時間不長。後來通過在windows的資源管理器中檢視實時磁碟IO，發現寫入1.txt的程式雖然已經退出了，但是磁碟還在寫入，說明這會是核心在往磁碟中寫入呢。而我此時啟動另一個測試程式對2.txt做寫入操作，會響測試1.txt效果，應該等1.txt完全寫入完成，磁碟io不再進行時候再啟動對2.txt的操作。

迴圈10000條，資料總量41080000：
系統預設檔案緩衝區大小 = 4096 byte,總共802344塊
預設緩衝區寫檔案，用時:0.468300
迴圈10000條，資料總量41080000：
自定義緩衝區 = 40960 byte
自定義緩衝區寫檔案，用時:0.155844

迴圈100000條，資料總量410800000：
系統預設檔案緩衝區大小 = 4096 byte,總共8023438塊
預設緩衝區寫檔案，用時:4.686463
迴圈100000條，資料總量410800000：
自定義緩衝區 = 40960 byte
自定義緩衝區寫檔案，用時:1.543402

迴圈1000000條，資料總量4108000000：
系統預設檔案緩衝區大小 = 4096 byte,總共2642816塊
預設緩衝區寫檔案，用時:47.181843
迴圈1000000條，資料總量4108000000：
自定義緩衝區 = 40960 byte
自定義緩衝區寫檔案，用時:28.394735

在寫入100000條之前，還有著2倍多的速率差異。
等到寫入次數達到1000000條的時候，兩者的時間差縮小到了1倍以內，此時的日誌檔案4.16G。再加大測試的話，核心的IO佇列該不夠用。
在windows下查看了下虛擬機器的寫入速率，依然自定義快取方式要快一些，以下是速率峰值時候的截圖
1.用系統預設快取

最高到74M/s
2.自定義快取峰值

最高到115M/s
從每次測試的結果看，自定義緩衝區後，寫入相同位元組的內容，自定義緩衝區明顯要比系統預設少一倍以上的時間。當然這是測試，實際專案可根據情況自行調節緩衝區大小。
不過這樣做的壞處顯而易見，斷電就抓瞎了，大量的的快取還沒寫到磁碟呢！

調等緩衝區

當然，我們還要測試下設定成和系統預設4096，也就是一個頁大小的單位

迴圈1000000條，資料總量4108000000：
系統預設檔案緩衝區大小 = 4096 byte,總共79633800塊
預設緩衝區寫檔案，用時:48.648003
迴圈1000000條，資料總量4108000000：
自定義緩衝區 = 4096 byte
自定義緩衝區寫檔案，用時:49.252640

用時幾乎相當，還多了1秒，呵呵。

調小緩衝區

再看看，縮小緩衝區的結果，設為1024位元組

迴圈1000000條，資料總量4108000000：
系統預設檔案緩衝區大小 = 4096 byte,總共8023438塊
預設緩衝區寫檔案，用時:49.945450
迴圈1000000條，資料總量4108000000：
自定義緩衝區 = 1024 byte
自定義緩衝區寫檔案，用時:102.239960

這次看到緩衝區縮小後，明顯用時更多了，竟然超過1倍多的時間。

思考

FILE結構裡本身帶有一個緩衝。而核心在操作IO的時候會還有一個緩衝區，核心將緩衝區寫到磁碟也不是直接寫，而是放到其IO佇列中等待寫入。加大檔案緩衝區，也只是加大了使用者態的緩衝區，而核心態緩衝區是沒有變的，所以當用戶態緩衝區超過4096一個頁大小的時候，它從使用者地址空間拷貝到核心地址空間時候，應該是切分了好幾頁，分別加入核心IO的佇列中，準備寫入到磁碟上。

創建於2014-03-04深圳騰訊，更新於2016-07-06杭州。