Linux进程间文件更新延迟过高问题排查与优化咨询

问题场景 #

两个独立进程：Process A处理业务并向文件写入日志，Process B轮询该日志文件执行后续任务（类似Telegraf、Vector这类工具）。预期Process A写入新日志后，Process B能在1ms以内极低延迟读取，但生产环境频繁出现超过300ms的延迟。

原本认为该场景仅涉及内核页缓存，不涉及物理磁盘IO，延迟理应远低于1ms，需明确显著延迟的产生原因及优化方案。

复现情况 #

编写两个最小化程序复现问题：测试环境未出现300ms级延迟，但运行数分钟后仍有数次3ms级别的延迟。

运行命令 #

• 启动Process A生成日志：

./makelog tmp1.log

• 启动Process B轮询日志（第一列为延迟，单位微秒）：

./tailog tmp1.log 3000

• 延迟输出示例：

delay:3225, now:290152, last_read:282002, last_sleep:286233, line:286927 read_len:37
delay:6376, now:813159, last_read:806386, last_sleep:806387, line:806783 read_len:111
delay:3773, now:302125, last_read:293886, last_sleep:298138, line:298352 read_len:37
delay:5931, now:218568, last_read:213272, last_sleep:217525, line:212637 read_len:8

源码实现 #

Process A（makelog.c） #

#include <sys/time.h>
#include <stdlib.h>
#include <fcntl.h>
#include <stdio.h>
#include <sys/types.h>
#include <unistd.h>

int get_now_usec() {
    struct timeval tv;
    gettimeofday(&tv, NULL);
    return tv.tv_usec;
}

int main(int argc, char **argv)
{
    if (argc != 2) {
        printf("invalid argument\n");
        printf("Usage: %s filename\n", argv[0]);
        return 1;
    }

    int fd = open(argv[1], O_CREAT | O_WRONLY, 0644);
    if (fd < 0) {
        perror("open file");
        return 1;
    }

    char buf[300];
    while (1) {
        int slen = sprintf(buf, "linestart: %06d log blahblah hello\n", get_now_usec());
        int wlen = write(fd, buf, slen);
        if (wlen != slen) {
            perror("write file");
            return 1;
        }
        usleep(random() % 10000);
    }
    return 0;
}

Process B（tailog.c） #

#include <sys/time.h>
#include <stdlib.h>
#include <fcntl.h>
#include <string.h>
#include <sys/types.h>
#include <unistd.h>
#include <stdio.h>

int get_now_usec() {
    struct timeval tv;
    gettimeofday(&tv, NULL);
    return tv.tv_usec;
}

int main(int argc, char **argv)
{
    if (argc != 3) {
        printf("invalid argument\n");
        printf("Usage: %s filename timeout\n", argv[0]);
        return 1;
    }

    char *filename = argv[1];
    int threlhold = atoi(argv[2]);

    int fd = open(filename, O_RDONLY);
    lseek(fd, 0, SEEK_END);
    char buf[1024*1024];
    int last_sleep = 0;
    int last_read = 0;
    while (1) {
        int len = read(fd, buf, sizeof(buf));
        if (len < 0) {
            perror("read file");
            break;
        }
        if (len == 0) {
            last_sleep = get_now_usec();
            usleep(1000); // 1ms
            continue;
        }
        if (memcmp(buf, "linestart: ", 11) != 0) {
            continue;
        }

        buf[17] = '\0';
        int log_us = atoi(&buf[11]);

        int now = get_now_usec();
        int delay = now - log_us;
        if (delay > threlhold) {
            printf("delay:%d, now:%d, last_read:%d, last_sleep:%d, line:%s read_len:%d\n",
                    delay, now, last_read, last_sleep, buf+11, len);
        }

        last_read = now;
    }
    return 1;
}

延迟原因分析 #

1. 内核页缓存同步机制：写入操作虽先到页缓存，但内核不会实时同步所有打开该文件进程的文件元数据（如文件大小）和缓存视图。Process B的read操作依赖内核同步这些数据，同步存在延迟。
2. 进程调度不确定性：Linux进程调度受系统负载影响，Process B可能被调度器挂起，导致usleep(1000)后无法立即唤醒，或唤醒后等待CPU时间片，累积延迟。生产环境负载更高，这种延迟会被放大到300ms级别。
3. usleep精度偏差：usleep的实际休眠时间可能因内核定时器精度、系统负载偏离预期，比如实际休眠超过1ms，拉长轮询间隔，错过日志写入窗口。
4. 页缓存锁竞争：内核后台写回线程（如writeback）执行磁盘写回时，可能对页缓存加锁，Process B读取时需等待锁释放，产生延迟。

优化方案 #

1. 替换轮询为事件驱动（inotify）：使用Linux的inotify机制监听文件IN_MODIFY或IN_CLOSE_WRITE事件，当Process A写入时内核主动通知Process B，彻底消除轮询延迟，这是最优方案。
2. 优化轮询策略：
   • 改用精度更高的nanosleep替代usleep，它不受信号干扰，休眠时间更接近预期；
   • 结合fstat获取文件大小，仅当文件大小变化时执行read，减少无效IO，但无法完全避免轮询延迟。
3. 调整进程优先级：给Process B设置更高优先级（通过nice命令或schd_setscheduler系统调用），让调度器更倾向于调度它，降低调度延迟。
4. 减少单文件锁竞争：将日志按时间分片写入多个小文件，降低单个文件的页缓存锁竞争概率。

内容的提问来源于stack exchange，提问作者wub