修改FILE缓冲区大小,改进写日志性能

由于线上服务端程序,需要大量写入日志,将来入数据库库,以便做数据分析或者对账之用,可是发现日志打开后服务器变慢了,对外并发响应数量也减少了。于是分析了下日志写入函数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杭州。

发布了43 篇原创文章 · 获赞 32 · 访问量 14万+
展开阅读全文

没有更多推荐了,返回首页

©️2019 CSDN 皮肤主题: 大白 设计师: CSDN官方博客

分享到微信朋友圈

×

扫一扫,手机浏览