是什么限制了 fwrite() 对 Linux 上完整磁盘的调用？答案

【问题标题】：What throttles the fwrite() calls to a full disk on linux?是什么限制了 fwrite() 对 Linux 上完整磁盘的调用？
【发布时间】：2015-01-19 20:26:16
【问题描述】：

看来，如果我的程序尝试写入完整的文件系统，它最初几乎会立即出现“设备上没有剩余空间”的错误，但如果我让它运行一分钟左右，它会减慢几倍数量级。

请注意，这是一个最小的测试用例，这种行为首先是在 Java 日志框架中发现的，因此输出块很小（512 字节）并且其中很多。

main.c

#include <stdlib.h>
#include <stdio.h>
#include <stdbool.h>
#include <stddef.h>
#include <time.h>
#include <sys/time.h>


long microTime() {
    struct timeval time;
    gettimeofday(&time, NULL);

    return time.tv_sec * 1000 * 1000 + time.tv_usec;
}

int main(int argc, const char * argv[]) {

    char *payload ;
    payload = (char *)malloc(512 * sizeof(char));

    if (payload == NULL) {
        printf("Failed to alloc memory\n");
        exit(1);
    }

    FILE *fp;
    fp = fopen(argv[1], "a+");

    printf("opened [%s]\n", argv[1]);

    if (fp == NULL) {
        printf("Failed to open [%s]\n", argv[1]);
        exit(1);
    }

    for (;;) {
        int batchSize = 100000;
        bool errored = false;
        long runStart = microTime();
        for (int i = 0; i < batchSize; i ++) {
            size_t result = fwrite(payload, 512 * sizeof(char), 1, fp);
            if (result == 0 && !errored) {
                perror("Failed to write to disk");
                errored = true;
            }

        }
        long runEnd = microTime();
        printf("total elapsed %dms\n", (int)(runEnd - runStart) / 1000);
    }

    return 0;
}

（请原谅我的C，这可能是我近20年来写的第一个C程序）

跑步：

gcc -std=c99 main.c && ./a.out /path/to/somewhere/file1.bin

警告此程序将填满您的磁盘分区

输出：

total elapsed 42ms
total elapsed 105ms
total elapsed 104ms
total elapsed 125ms
... skip until the disk fills
Failed to write to disk: No space left on device
total elapsed 104ms
Failed to write to disk: No space left on device
total elapsed 76ms
Failed to write to disk: No space left on device
total elapsed 84ms
Failed to write to disk: No space left on device
... then skip a little more about one minute
total elapsed 8096ms
Failed to write to disk: No space left on device
total elapsed 43245ms
Failed to write to disk: No space left on device
total elapsed 48670ms
Failed to write to disk: No space left on device
total elapsed 45929ms
Failed to write to disk: No space left on device

我的期望是这个程序将永远运行，并且写入磁盘的恒定时间相当短。

我已经在本地 centos 6.4 vagrant box、amazon linux 和 ubuntu 14.04 ec2 box 上运行，结果完全相同。有趣的是，在尝试填充磁盘映像的 OSX 10.9.5 上似乎不会发生这种情况。

所以我的问题是，究竟是什么导致了这种明显的节流？

更新：使用 strace -t -T 运行

10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096 <0.000011>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096 <0.000011>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000066>
10:27:38 dup(2)                         = 4 <0.000006>
10:27:38 fcntl(4, F_GETFL)              = 0x8002 (flags O_RDWR|O_LARGEFILE) <0.000011>
10:27:38 fstat(4, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000006>
10:27:38 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa8e97f2000 <0.000009>
10:27:38 lseek(4, 0, SEEK_CUR)          = -1 ESPIPE (Illegal seek) <0.000005>
10:27:38 write(4, "Failed to write to disk: No spac"..., 49Failed to write to disk: No space left on device
) = 49 <0.000006>
10:27:38 close(4)                       = 0 <0.000006>
10:27:38 munmap(0x7fa8e97f2000, 4096)   = 0 <0.000015>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000026>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000017>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000016>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000016>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000015>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000016>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000015>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000015>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000016>
10:27:38 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.000016>

... skipping to the end
10:30:02 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.005747>
10:30:02 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.005231>
10:30:02 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.005496>
10:30:02 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.005870>
10:30:02 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.005823>
10:30:02 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = -1 ENOSPC (No space left on device) <0.005841>

到运行结束时，write() 的调用时间不是从 ~0.00001s => ~0.005s。

The full run.log is 250mb

更新 2：为各个阶段添加 CPU 使用详细信息：

盯着运行，即填满磁盘

top - 11:00:56 up  2:52,  2 users,  load average: 1.79, 0.99, 0.48
Tasks:  75 total,   3 running,  72 sleeping,   0 stopped,   0 zombie
Cpu(s):  7.3%us, 71.8%sy,  0.0%ni,  0.0%id,  0.0%wa, 14.6%hi,  6.3%si,  0.0%st
Mem:    603764k total,   561868k used,    41896k free,   134976k buffers
Swap:  1254392k total,        0k used,  1254392k free,   359020k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 9861 vagrant   20   0  4056  500  412 R 54.5  0.1   0:01.88 a.out
  766 root      20   0     0    0    0 R 36.9  0.0   0:28.51 flush-8:0
   28 root      20   0     0    0    0 S  5.6  0.0   0:05.14 kswapd0
   16 root      20   0     0    0    0 S  2.3  0.0   4:51.07 kblockd/0

磁盘已满，快速出错

top - 11:01:11 up  2:52,  2 users,  load average: 1.68, 1.01, 0.49
Tasks:  75 total,   2 running,  73 sleeping,   0 stopped,   0 zombie
Cpu(s):  9.0%us, 91.0%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:    603764k total,   555424k used,    48340k free,   134976k buffers
Swap:  1254392k total,        0k used,  1254392k free,   352224k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 9861 vagrant   20   0  4056  552  464 R 99.5  0.1   0:12.91 a.out
  988 root      20   0  215m 1572  860 S  0.3  0.3   0:05.05 VBoxService
    1 root      20   0 19228 1348 1072 S  0.0  0.2   0:00.24 init
    2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 kthreadd

缓慢的错误

top - 11:03:03 up  2:54,  2 users,  load average: 1.63, 1.14, 0.59
Tasks:  74 total,   3 running,  71 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0%us,  0.4%sy,  0.0%ni,  0.0%id, 98.8%wa,  0.4%hi,  0.4%si,  0.0%st
Mem:    603764k total,   555284k used,    48480k free,   134976k buffers
Swap:  1254392k total,        0k used,  1254392k free,   352308k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  216 root      20   0     0    0    0 R  3.7  0.0   4:50.72 jbd2/sda1-8
   16 root      20   0     0    0    0 R  3.3  0.0   4:53.04 kblockd/0
 9861 vagrant   20   0  4056  552  464 D  1.3  0.1   1:17.47 a.out
    1 root      20   0 19228 1348 1072 S  0.0  0.2   0:00.24 init

【问题讨论】：

我的猜测是它正在文件系统中寻找空间，当文件系统已满时这会很慢。
将第2个和第3个参数交换为fwrite()时，测试的表现如何？
Gareth: 你能在strace 下运行你的代码并发布输出吗？跟踪时间（-t、-T 等可能有很大帮助）。
但它设法返回“设备上没有剩余空间”大约一分钟，然后变慢。此时已经发现磁盘已满好几次（几百万次）
@Gareth，您使用的是哪个文件系统？快速搜索表明，在ENOSPC 条件下，至少 XFS 可以通过节流来做一些有趣的事情。

标签： c linux

【解决方案1】：

当write 系统调用阻塞并变为同步时，您可能正在观察 Linux 虚拟内存的影响。这是因为您的应用程序会不断生成要写入磁盘的数据，而磁盘无法快速存储数据。

或者，在磁盘被填满后的某个时间，后台刷新启动，因此write 系统调用与内核刷新线程竞争对文件系统内部结构的访问，因此返回ENOSPC 需要更长的时间.

见Better Linux Disk Caching & Performance with vm.dirty_ratio & vm.dirty_background_ratio:

vm.dirty_background_ratio 是在 pdflush/flush/kdmflush 后台进程启动以将其写入磁盘之前，可以被“脏”页面（仍需要写入磁盘的内存页面）填充的系统内存百分比。我的示例是 10%，所以如果我的虚拟服务器有 32 GB 的内存，那么在完成某事之前可以将 3.2 GB 的数据放在 RAM 中。

vm.dirty_ratio 是在所有内容都必须提交到磁盘之前可以用脏页填充的系统内存的绝对最大量。 当系统到达这一点时，所有新的 I/O 都会阻塞，直到脏页被写入磁盘。这通常是长时间 I/O 暂停的原因，但可以防止过多的数据不安全地缓存在内存中。

【讨论】：

当然，写入不应该达到缓存，因为它们被正确拒绝，因为磁盘已满。
@GarethDavis 我猜write 必须阻止直到vm.dirty_ratio 阈值恢复。到阈值恢复时，文件系统状态可能已经改变，并且有更多可用空间。
有什么方法可以检验这个理论吗？所以如果我改变 vm. dirty_background_ratio 为 1，“慢错误”是否应该更早发生？
@MaximYegorushkin 如果是脏页限制，它会在我们用完空间之前触发，而不是 35 秒后。如果您查看日志，文件系统会在 10:27:38 填满，并且每次失败的 write 调用所花费的时间直到 10:28:13 才会变高。
@Art 我添加了一个替代假设。