如何确定使用带有 setvbuf 函数的 _IONBF 宏,文件操作很慢

How to ascertain that using the _IONBF macro with the setvbuf function, file operations are slow

我想举个明确的例子,实际在setvbuf函数中使用_IONBF宏,文件中的写入操作(流)直接发生,而不使用缓冲区。 如果我在我的文件系统(SSD 内存)上做这个实验,我不会看到任何写入延迟,因为它是一个非常快的设备,但如果我用软盘做这个,我将不得不看到,当我 运行 程序,我终端的命令提示符,写入软盘结束后立即释放。

为什么在我看来写入仍然是通过缓冲区进行的?

注意:在程序字符串中,我复制/粘贴了一段很长的文本(1.44 MB 字符);所以如果你想尝试这个实验(除了软盘驱动器),你必须填充足够的字符串以使设备上的写入变慢。

#include <stdio.h>
#include <string.h>

int main() {
    FILE *fp;
    char string[] = "here goes a very long text .... enough to fill a floppy disk!";

    fp = freopen("/Volumes/FLOPPY/file.txt", "w", stdout);
    setvbuf(fp, NULL, _IONBF, 0);
    printf("%s", string);
    printf("\nEND OF FILE");

    fclose(fp);
    return(0);
}




printf() 函数可能会将您的请求映射到单个 write() 调用,不使用缓冲,但也不会减慢速度。如果想看不缓冲的效果,使用单字符I/O:

for (int i = 0; string[i] != '[=10=]'; i++)
    putc(string[i], fp);

对于无缓冲的 I/O,这将显示出差异,因为每次调用 putc() 都需要一个 write() 系统调用,因为只有一个字节可用于处理。

请注意,下面的代码不适用于字符串 — 它适用于字节数组(无空终止符)。差异对性能并不重要;它确实需要在处理数据时稍加小心。

该代码还使用常规 fopen() 而不是在 stdout 上使用 freopen()。同样,这不会(极不可能)对性能产生 material 差异。

slow11.c

#include <stdio.h>

#define FLOPPY_SIZE (2 * 80 * 18 * 512) // 2 sides, 80 tracks, 18 sectors, 512 bytes

int main(void)
{
    char string[FLOPPY_SIZE];

    for (size_t i = 0; i < FLOPPY_SIZE; i++)
        string[i] = (i % 64) + '0';

    const char filename[] = "floppy.data";
    FILE *fp = fopen(filename, "w");
    setvbuf(fp, NULL, _IONBF, 0);

    for (size_t i = 0; i < FLOPPY_SIZE; i++)
        putc(string[i], fp);

    fclose(fp);

    return(0);
}

slow61.c

我还通过删除 setvbuf() 行从 slow11.c 创建了一个程序 slow61.c

fast89.c

#include <stdio.h>

#define FLOPPY_SIZE (2 * 80 * 18 * 512) // 2 sides, 80 tracks, 18 sectors, 512 bytes

int main(void)
{
    char string[FLOPPY_SIZE];

    for (size_t i = 0; i < FLOPPY_SIZE; i++)
        string[i] = (i % 64) + '0';

    const char filename[] = "floppy.data";
    FILE *fp = fopen(filename, "w");
    setvbuf(fp, NULL, _IONBF, 0);

    fprintf(fp, "%.*s", FLOPPY_SIZE, string);

    fclose(fp);

    return(0);
}

采样运行次

timecmd 程序是自制程序; -u 选项以微秒为单位报告时间(-n 表示纳秒;-m 表示毫秒,整秒没有任何内容)。它主要用于 long-运行ning 程序,它有助于了解命令何时开始,以便您可以猜测它何时结束(这就是它报告开始和结束信息的原因)。您可能可以使用 (POSIX standard) time 代替;输出格式会有所不同。

$ for i in 1 2 3 4 5 6 7 8 9 0; do timecmd -u -- fast89; timecmd -u slow61; timecmd -u slow11; done
2020-03-01 07:58:05.964614 [PID 14492] fast89
2020-03-01 07:58:05.978391 [PID 14492; status 0x0000]  -  0.013777s
2020-03-01 07:58:05.986902 [PID 14494] slow61
2020-03-01 07:58:06.058328 [PID 14494; status 0x0000]  -  0.071426s
2020-03-01 07:58:06.066949 [PID 14496] slow11
2020-03-01 07:58:09.788096 [PID 14496; status 0x0000]  -  3.721147s
2020-03-01 07:58:09.795178 [PID 14498] fast89
2020-03-01 07:58:09.806464 [PID 14498; status 0x0000]  -  0.011286s
2020-03-01 07:58:09.813784 [PID 14500] slow61
2020-03-01 07:58:09.882777 [PID 14500; status 0x0000]  -  0.068993s
2020-03-01 07:58:09.890567 [PID 14502] slow11
2020-03-01 07:58:13.689083 [PID 14502; status 0x0000]  -  3.798516s
2020-03-01 07:58:13.696225 [PID 14504] fast89
2020-03-01 07:58:13.708219 [PID 14504; status 0x0000]  -  0.011994s
2020-03-01 07:58:13.715447 [PID 14506] slow61
2020-03-01 07:58:13.784190 [PID 14506; status 0x0000]  -  0.068743s
2020-03-01 07:58:13.791485 [PID 14508] slow11
2020-03-01 07:58:17.495425 [PID 14508; status 0x0000]  -  3.703940s
2020-03-01 07:58:17.502710 [PID 14510] fast89
2020-03-01 07:58:17.514147 [PID 14510; status 0x0000]  -  0.011437s
2020-03-01 07:58:17.521541 [PID 14512] slow61
2020-03-01 07:58:17.589657 [PID 14512; status 0x0000]  -  0.068116s
2020-03-01 07:58:17.596818 [PID 14514] slow11
2020-03-01 07:58:21.253654 [PID 14514; status 0x0000]  -  3.656836s
2020-03-01 07:58:21.260930 [PID 14516] fast89
2020-03-01 07:58:21.272169 [PID 14516; status 0x0000]  -  0.011239s
2020-03-01 07:58:21.279587 [PID 14518] slow61
2020-03-01 07:58:21.348507 [PID 14518; status 0x0000]  -  0.068920s
2020-03-01 07:58:21.355832 [PID 14520] slow11
2020-03-01 07:58:25.041571 [PID 14520; status 0x0000]  -  3.685739s
2020-03-01 07:58:25.048497 [PID 14522] fast89
2020-03-01 07:58:25.059680 [PID 14522; status 0x0000]  -  0.011183s
2020-03-01 07:58:25.066855 [PID 14524] slow61
2020-03-01 07:58:25.135246 [PID 14524; status 0x0000]  -  0.068391s
2020-03-01 07:58:25.142421 [PID 14526] slow11
2020-03-01 07:58:28.853268 [PID 14526; status 0x0000]  -  3.710847s
2020-03-01 07:58:28.860497 [PID 14528] fast89
2020-03-01 07:58:28.872152 [PID 14528; status 0x0000]  -  0.011655s
2020-03-01 07:58:28.879254 [PID 14530] slow61
2020-03-01 07:58:28.947534 [PID 14530; status 0x0000]  -  0.068280s
2020-03-01 07:58:28.955126 [PID 14532] slow11
2020-03-01 07:58:33.236459 [PID 14532; status 0x0000]  -  4.281333s
2020-03-01 07:58:33.243709 [PID 14534] fast89
2020-03-01 07:58:33.260364 [PID 14534; status 0x0000]  -  0.016655s
2020-03-01 07:58:33.267575 [PID 14536] slow61
2020-03-01 07:58:33.336602 [PID 14536; status 0x0000]  -  0.069027s
2020-03-01 07:58:33.344791 [PID 14538] slow11
2020-03-01 07:58:37.065292 [PID 14538; status 0x0000]  -  3.720501s
2020-03-01 07:58:37.072215 [PID 14540] fast89
2020-03-01 07:58:37.083717 [PID 14540; status 0x0000]  -  0.011502s
2020-03-01 07:58:37.090785 [PID 14542] slow61
2020-03-01 07:58:37.158659 [PID 14542; status 0x0000]  -  0.067874s
2020-03-01 07:58:37.165790 [PID 14544] slow11
2020-03-01 07:58:41.024668 [PID 14544; status 0x0000]  -  3.858878s
2020-03-01 07:58:41.032007 [PID 14566] fast89
2020-03-01 07:58:41.043518 [PID 14566; status 0x0000]  -  0.011511s
2020-03-01 07:58:41.053114 [PID 14568] slow61
2020-03-01 07:58:41.128938 [PID 14568; status 0x0000]  -  0.075824s
2020-03-01 07:58:41.136826 [PID 14570] slow11
2020-03-01 07:58:44.971013 [PID 14570; status 0x0000]  -  3.834187s
$

不需要太多技巧就可以看出 slow11 代码的时间是 fast89 代码的 300 倍左右,而且非缓冲是关键因素,因为 slow61 只比 fast89.

慢 6-7 倍

在 MacBook Pro 上测试 运行使用 SSD 和 GCC 9.2.0 的 macOS Mojave 10.14.6。