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

Question

我想有一个明确的例子，在 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);
}

Answer 1

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

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

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

请注意，下面的代码不适用于字符串——它适用于字节数组（无空终止符）。差异对性能并不重要；在处理数据时确实需要一点小心。

代码还使用常规的fopen()，而不是在stdout 上使用freopen()。同样，这不会（极不可能）对性能产生重大影响。

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 表示毫秒，整秒都没有）。它主要用于长时间运行的程序，它有助于了解命令何时开始，以便您可以猜测它何时结束（这就是它报告开始和结束信息的原因）。您可以改用（POSIX 标准）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 只有大约6-比 fast89 慢 7 倍。

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