日志达到阈值后轮转，确认程序继续写入正确文件

日志达到阈值后轮转确认程序继续写入正确文件上一篇我们让debug_demo从配置文件读取日志周期并验证了配置缺失或无效时的回退行为。服务已经能够持续运行但日志仍不断追加到同一个文件运行时间越长/var/log/debug-demo.log就越大。这篇继续使用 Ubuntu、QEMU 和 Buildroot不需要开发板。我们给程序增加一个简单的大小阈值轮转活动日志达到 1 KiB 后将它改名为/var/log/debug-demo.log.1再重新打开/var/log/debug-demo.log并确认后续日志确实进入新的活动文件。一、这次要验证什么本文承接《让 ARM64 程序支持配置文件修改日志周期无需重新编译》。沿用 Buildroot 2025.02.8、QEMU ARM64、BusyBox init 及外部软件包debug-demo。本篇只处理一个问题日志文件达到设定大小后轮转服务是否会继续写入正确的活动日志文件轮转关系如下/var/log/debug-demo.log 达到 1 KiB | -- 当前活动文件改名为 /var/log/debug-demo.log.1 | -- 程序重新打开 /var/log/debug-demo.log | -- 后续服务日志写入新的活动文件为便于观察本例只保留一个备份文件。再次轮转时较早的.1会被新轮转出的活动文件替换。它是短时实验设计不是生产日志归档策略。二、为什么只改文件名不够程序打开日志文件时操作系统会给它一个文件描述符。后续即使把路径/var/log/debug-demo.log改名为/var/log/debug-demo.log.1进程原先持有的描述符仍指向那个已改名的文件对象重新创建同名路径不会自动让程序改写新文件。因此单独执行mv并创建同名文件不足以证明轮转成功程序必须重新打开活动日志。第五节介绍实现方式第九节用文件内容验证写入去向。本例由应用自己检查文件大小不使用外部logrotate服务。检查发生在每条日志写入并刷新之后所以文件大小可能超过阈值一条日志记录1 KiB 是触发阈值不是绝对字节上限。轮转和重新打开的文件位于同一个/var/log文件系统中。三、环境与操作约定项目本文沿用的设置开发主机Ubuntu 20.04 x86_64 虚拟机Buildroot2025.02.8~/buildroot-2025.02.8输出目录~/buildroot-output-arm64-demo外部目录~/buildroot-external-demo标识ARM64_DEMO目标系统QEMU ARM64BusyBox init服务程序/usr/bin/debug_demo --service活动日志/var/log/debug-demo.log单个轮转备份/var/log/debug-demo.log.1轮转阈值1024 字节1 KiB默认命令在Ubuntu 主机执行只有标注QEMU 目标端的命令才在 ARM64 系统内执行。不要在 Windows PowerShell 执行本文的 Bash 命令。本篇不修改/etc/inittab、S99debug-demo、BusyBox 配置或软件包选择服务仍由上一篇的 BusyBox initrespawn项管理。确认目标端只运行一个服务实例不要手动再启动第二个--service。四、关机并备份源码如果上一篇的 QEMU 仍在运行先在QEMU 目标端正常关机poweroff等待系统关机。如果 QEMU 进程仍未退出再按CtrlA松开后按X。确认 QEMU 已释放可写镜像再从 Ubuntu 主机修改并重建。在Ubuntu 主机备份外部目录和当前 Buildroot 配置exportDEMO_OUT$HOME/buildroot-output-arm64-demoexportLOG_BACKUP$HOME/debug-demo-before-log-rotation-$(date%Y%m%d-%H%M%S)(set-eutest-f$DEMO_OUT/.configtest-f$HOME/buildroot-external-demo/src/debug-demo/debug_demo.cmkdir$LOG_BACKUPcp-a$HOME/buildroot-external-demo$LOG_BACKUP/cp-p$DEMO_OUT/.config$LOG_BACKUP/buildroot.configprintfBackup: %s\n$LOG_BACKUP)echo$?预期返回0。保留打印出的备份目录如有检查或复制失败先停止并排查不要继续覆盖源码。五、为程序加入大小检查和安全重开在Ubuntu 主机执行下面的完整命令替换debug_demo.c。本版保留上一篇的配置解析、信号处理、无参数求和输出和服务日志格式并增加大小检查与轮转函数。cd~/buildroot-external-demo||exit1catsrc/debug-demo/debug_demo.cEOF #define _POSIX_C_SOURCE 200809L #include ctype.h #include errno.h #include signal.h #include stdio.h #include stdlib.h #include string.h #include sys/stat.h #include time.h #include unistd.h #define CONFIG_PATH /etc/debug-demo.conf #define LOG_PATH /var/log/debug-demo.log #define ROTATED_LOG_PATH /var/log/debug-demo.log.1 #define DEFAULT_INTERVAL_SEC 2U #define MAX_INTERVAL_SEC 60L #define MAX_LOG_BYTES 1024 static volatile sig_atomic_t running 1; static void handle_signal(int signal_number) { (void)signal_number; running 0; } int compute_total(const int *values, int count) { int total 0; for (int index 0; index count; index) { total values[index]; } return total; } static unsigned int load_interval(const char **status) { char buffer[256]; const char prefix[] interval_sec; FILE *config_file fopen(CONFIG_PATH, r); if (config_file NULL) { *status errno ENOENT ? missing-default : read-error-default; return DEFAULT_INTERVAL_SEC; } size_t length fread(buffer, 1, sizeof(buffer), config_file); int read_failed ferror(config_file); int close_failed fclose(config_file); if (read_failed || close_failed ! 0) { *status read-error-default; return DEFAULT_INTERVAL_SEC; } *status invalid-default; if (length sizeof(buffer) || memchr(buffer, \0, length) ! NULL) { return DEFAULT_INTERVAL_SEC; } buffer[length] \0; char *begin buffer; while (isspace((unsigned char)*begin)) { begin; } char *end buffer length; while (end begin isspace((unsigned char)end[-1])) { --end; } *end \0; if (strncmp(begin, prefix, sizeof(prefix) - 1) ! 0) { return DEFAULT_INTERVAL_SEC; } char *number begin sizeof(prefix) - 1; if (*number \0) { return DEFAULT_INTERVAL_SEC; } for (const char *cursor number; *cursor ! \0; cursor) { if (*cursor 0 || *cursor 9) { return DEFAULT_INTERVAL_SEC; } } errno 0; char *number_end NULL; long parsed strtol(number, number_end, 10); if (errno ! 0 || *number_end ! \0 || parsed 1 || parsed MAX_INTERVAL_SEC) { return DEFAULT_INTERVAL_SEC; } *status loaded; return (unsigned int)parsed; } static int rotate_log(FILE **log_file) { FILE *old_log *log_file; if (fflush(old_log) ! 0) { return -1; } *log_file NULL; if (fclose(old_log) ! 0) { return -1; } if (rename(LOG_PATH, ROTATED_LOG_PATH) ! 0) { int rename_error errno; *log_file fopen(LOG_PATH, a); if (*log_file NULL) { return -1; } errno rename_error; perror(rename active log; continuing with current file); return 0; } *log_file fopen(LOG_PATH, a); if (*log_file NULL) { int open_error errno; if (rename(ROTATED_LOG_PATH, LOG_PATH) 0) { *log_file fopen(LOG_PATH, a); } if (*log_file NULL) { errno open_error; return -1; } errno open_error; perror(open new active log; restored previous path); return 0; } if (fprintf(*log_file, debug-demo log: rotation complete; active file reopened pid%ld\n, (long)getpid()) 0 || fflush(*log_file) ! 0) { return -1; } return 1; } static int rotate_if_needed(FILE **log_file) { struct stat log_status; if (fflush(*log_file) ! 0 || fstat(fileno(*log_file), log_status) ! 0) { return -1; } if (log_status.st_size MAX_LOG_BYTES) { return 0; } return rotate_log(log_file) 0 ? -1 : 0; } int main(int argc, char *argv[]) { const int values[] {10, 20, 30, 40}; int result compute_total(values, 4); if (argc 1) { printf(debug-demo package v2: total %d\n, result); return 0; } if (argc ! 2 || strcmp(argv[1], --service) ! 0) { fprintf(stderr, Usage: %s [--service]\n, argv[0]); return 1; } struct sigaction action {0}; action.sa_handler handle_signal; sigemptyset(action.sa_mask); if (sigaction(SIGTERM, action, NULL) ! 0 || sigaction(SIGINT, action, NULL) ! 0) { perror(sigaction); return 1; } FILE *log_file fopen(LOG_PATH, a); if (log_file NULL) { perror(open log); return 1; } const char *config_status NULL; unsigned int interval_sec load_interval(config_status); const char *level strcmp(config_status, loaded) 0 ? INFO : WARN; if (fprintf(log_file, debug-demo config: pid%ld level%s path%s status%s interval_sec%u\n, (long)getpid(), level, CONFIG_PATH, config_status, interval_sec) 0 || fflush(log_file) ! 0) { fclose(log_file); return 1; } if (rotate_if_needed(log_file) ! 0) { perror(check or rotate log); if (log_file ! NULL) { fclose(log_file); } return 1; } unsigned long tick 0; while (running) { struct timespec timestamp; if (clock_gettime(CLOCK_MONOTONIC, timestamp) ! 0) { perror(clock_gettime); fclose(log_file); return 1; } if (fprintf(log_file, debug-demo service: pid%ld tick%lu mono%lld.%09ld interval_sec%u total%d\n, (long)getpid(), tick, (long long)timestamp.tv_sec, timestamp.tv_nsec, interval_sec, result) 0 || fflush(log_file) ! 0) { fclose(log_file); return 1; } if (rotate_if_needed(log_file) ! 0) { perror(check or rotate log); if (log_file ! NULL) { fclose(log_file); } return 1; } for (unsigned int elapsed 0; running elapsed interval_sec; elapsed) { struct timespec remaining {1, 0}; while (running nanosleep(remaining, remaining) ! 0) { if (errno ! EINTR) { perror(nanosleep); fclose(log_file); return 1; } } } } if (fprintf(log_file, debug-demo service: pid%ld stopped\n, (long)getpid()) 0) { fclose(log_file); return 1; } return fclose(log_file) 0 ? 0 : 1; } EOF1. 轮转实现的关键点每条日志写入后立即fflush再用fstat检查当前打开文件的大小。达到 1024 字节后先关闭当前流再把活动文件改名为.1最后重新打开活动路径。重新打开后程序写入rotation complete标记。新活动文件和.1的内容可以用来交叉验证轮转边界。只保留一个备份。再次轮转时新的.1替换旧.1日志记录不会无限堆积。如果改名失败但原活动文件可以重新打开程序向标准错误报告问题并继续写入原文件如果无法恢复可写日志则服务退出。BusyBox init 会按respawn再启动它因此真实部署还需要设计磁盘故障处理和重试限制。阈值按日志记录检查不会在一条记录中间截断。文件可能超过阈值一条记录的大小这是本篇“达到阈值后轮转”的具体定义不是精确硬限制。六、软件包规则不需要改变本篇只修改应用源码默认配置仍由前文的包规则安装服务仍由inittab直接启动。确认外部目录中已有src/debug-demo/debug_demo.c package/debug-demo/debug-demo.mk package/debug-demo/S99debug-demo package/debug-demo/debug-demo.conf board/qemu-arm64-demo/rootfs-overlay/etc/inittab本篇不新增第二个软件包不改BR2_PACKAGE_DEBUG_DEMO、overlay 或 init 配置。继续使用原有-O0 -g -gdwarf-4调试选项若出现_FORTIFY_SOURCE与-O0相关告警其含义仍是对应加固在当前参数下未生效。七、重建程序和文件系统镜像先确认 QEMU 已完全退出再在Ubuntu 主机执行。不要让 QEMU 同时使用正在构建的可写镜像exportDEMO_OUT$HOME/buildroot-output-arm64-demo(set-eucd$HOME/buildroot-2025.02.8makeO${DEMO_OUT:?请先设置 DEMO_OUT}\BR2_EXTERNAL$HOME/buildroot-external-demodebug-demo-rebuildV1makeO${DEMO_OUT:?请先设置 DEMO_OUT}\BR2_EXTERNAL$HOME/buildroot-external-demo-j2)echo$?应返回0。第一条命令重新同步并编译本地包第二条命令生成根文件系统镜像。只完成包重建而未执行完整构建不足以确认启动镜像已更新。不要为了本次源码变更重新加载官方 defconfig 或执行make clean。在Ubuntu 主机核对构建结果file$DEMO_OUT/target/usr/bin/debug_demogrep-nFx::respawn:/usr/bin/debug_demo --service$DEMO_OUT/target/etc/inittabcat$DEMO_OUT/target/etc/debug-demo.confls-l$DEMO_OUT/images/rootfs.ext2确认程序为 AArch64 ELFinittab仍只有预期监督项默认周期符合包配置。该检查只能说明构建目录中的产物轮转行为仍要在 QEMU 实际运行镜像验证。本次主机端实测确认debug_demo是 64 位 AArch64 动态链接 ELFinittab第 42 行包含预期的respawn项默认配置为interval_sec2rootfs.ext2已生成大小为 60 MiB。这些结果只确认了构建目录中的产物尚未验证 QEMU 启动后的轮转行为。八、启动 QEMU 并检查单实例在Ubuntu 主机启动 QEMUexportDEMO_OUT$HOME/buildroot-output-arm64-demo/usr/bin/qemu-system-aarch64\-Mvirt\-cpucortex-a53\-smp2\-m1G\-nographic\-kernel${DEMO_OUT:?请先设置 DEMO_OUT}/images/Image\-appendrootwait root/dev/vda consolettyAMA0\-drivefile$DEMO_OUT/images/rootfs.ext2,ifnone,formatraw,idhd0\-devicevirtio-blk-device,drivehd0\-netdevuser,idnet0\-devicevirtio-net-device,netdevnet0登录提示出现后以root登录。下面命令在QEMU 目标端执行cat/etc/debug-demo.conf pidof debug_demops|grep[d]ebug_demotail-n8/var/log/debug-demo.log预期配置文件为interval_sec2且只有一个/usr/bin/debug_demo --service。若 PID 不唯一或程序未运行先检查inittab、程序启动和日志目录不要手动再启动一个实例。本次目标端初始检查结果如下# cat /etc/debug-demo.conf interval_sec2 # pidof debug_demo 119 # ps | grep [d]ebug_demo 119 root /usr/bin/debug_demo --service # tail -n 8 /var/log/debug-demo.log debug-demo log: rotation complete; active file reopened pid119 debug-demo service: pid119 tick25 mono68.059861568 interval_sec2 total100检查时配置为两秒只有 PID 119 的服务实例活动日志中已出现重开标记和后续服务日志说明至少一次轮转已发生在这次查看之前。此输出尚未检查.1备份内容下面继续核对轮转前后的两个文件。九、等待轮转并确认新日志去向本例阈值为 1 KiB按默认两秒周期通常需要若干条日志后触发。等待一段时间再检查活动文件、备份文件的大小和内容sleep25ls-l/var/log/debug-demo.log /var/log/debug-demo.log.1wc-c/var/log/debug-demo.log /var/log/debug-demo.log.1tail-n8/var/log/debug-demo.logtail-n8/var/log/debug-demo.log.1由于系统负载、日志行长度以及启动时已有文件大小可能不同25 秒后未必恰好得到同一组行数。如果.1尚未出现继续等待几个日志周期再检查不要手工mv活动文件否则会绕开本篇正在验证的程序重开逻辑。本次 QEMU 目标端实测如下# sleep 25 # ls -l /var/log/debug-demo.log /var/log/debug-demo.log.1 -rw-r--r-- 1 root root 711 Oct 26 02:20 /var/log/debug-demo.log -rw-r--r-- 1 root root 1024 Oct 26 02:20 /var/log/debug-demo.log.1 # wc -c /var/log/debug-demo.log /var/log/debug-demo.log.1 711 /var/log/debug-demo.log 1024 /var/log/debug-demo.log.1 1735 total # tail -n 8 /var/log/debug-demo.log debug-demo service: pid119 tick99 mono217.177468224 interval_sec2 total100 debug-demo service: pid119 tick100 mono219.195770976 interval_sec2 total100 debug-demo service: pid119 tick101 mono221.210164688 interval_sec2 total100 debug-demo service: pid119 tick102 mono223.223501808 interval_sec2 total100 debug-demo service: pid119 tick103 mono225.233461680 interval_sec2 total100 debug-demo service: pid119 tick104 mono227.247304160 interval_sec2 total100 debug-demo service: pid119 tick105 mono229.259803216 interval_sec2 total100 debug-demo service: pid119 tick106 mono231.267265456 interval_sec2 total100 # tail -n 8 /var/log/debug-demo.log.1 debug-demo service: pid119 tick91 mono201.075746624 interval_sec2 total100 debug-demo service: pid119 tick92 mono203.089506080 interval_sec2 total100 debug-demo service: pid119 tick93 mono205.102247328 interval_sec2 total100 debug-demo service: pid119 tick94 mono207.111994384 interval_sec2 total100 debug-demo service: pid119 tick95 mono209.119731424 interval_sec2 total100 debug-demo service: pid119 tick96 mono211.131586592 interval_sec2 total100 debug-demo service: pid119 tick97 mono213.147046448 interval_sec2 total100 debug-demo service: pid119 tick98 mono215.161938464 interval_sec2 total100.1大小为阈值 1024 字节活动文件为 711 字节备份末尾 tick 98 后活动文件从 tick 99 接续PID 始终为 119。这组结果确认轮转边界处的日志连续且轮转后服务继续写入活动文件。此处tail未展示活动文件前部的rotation complete标记下一步再用grep检查该标记是否仍在活动文件中若后续又发生轮转标记也可能已经随旧活动文件进入.1。再核对活动文件是否包含当前 PID 的轮转标记及更新的tick并观察 PID 是否稳定current_pid$(pidof debug_demo)grep-Frotation complete; active file reopened pid$current_pid\/var/log/debug-demo.logtail-n5/var/log/debug-demo.logsleep6pidof debug_demotail-n5/var/log/debug-demo.log本次目标端的后续检查结果如下# current_pid$(pidof debug_demo) # grep -F rotation complete; active file reopened pid$current_pid \ /var/log/debug-demo.log debug-demo log: rotation complete; active file reopened pid119 # tail -n 5 /var/log/debug-demo.log debug-demo service: pid119 tick147 mono313.990103216 interval_sec2 total100 debug-demo service: pid119 tick148 mono316.006296960 interval_sec2 total100 debug-demo service: pid119 tick149 mono318.019297776 interval_sec2 total100 debug-demo service: pid119 tick150 mono320.028412160 interval_sec2 total100 debug-demo service: pid119 tick151 mono322.035023744 interval_sec2 total100 # sleep 6 # pidof debug_demo 119 # tail -n 5 /var/log/debug-demo.log debug-demo service: pid119 tick151 mono322.035023744 interval_sec2 total100 debug-demo service: pid119 tick152 mono324.162579232 interval_sec2 total100 debug-demo service: pid119 tick153 mono326.179358432 interval_sec2 total100 debug-demo service: pid119 tick154 mono328.201561200 interval_sec2 total100 debug-demo service: pid119 tick155 mono330.212640544 interval_sec2 total100活动文件中找到 PID 119 的重开标记等待六秒后PID 仍为 119tick 从 151 增至 155日志继续写入活动路径。这与上一项.1中 tick 9198、活动文件从 tick 99 接续的记录相互印证确认该次轮转后服务仍在向正确文件写入。若其他运行中标记已随下一次轮转移入.1说明服务又完成了一次轮转此时检查当前活动文件中的最新服务日志并比较.1末尾与活动文件开头的tick。较新的 tick 应出现在活动文件中而非只留在旧备份里。不能仅凭debug_demo进程仍存在就断言轮转成功。关键证据是轮转后活动路径重新打开并且当前服务后续写入出现在新的活动文件中。十、常见情况与本篇边界现象说明或检查方向.1还不存在文件尚未达到阈值再等几个周期确认程序确实在写日志活动文件大小略高于 1 KiB按完整日志记录检查允许最后一条记录造成小幅超出.1每次轮转后内容变化本篇只保留一个备份旧.1会被下一轮替换有.1活动文件却没有轮转标记检查轮转后是否成功重开也可能标记已进入下一次轮转的.1服务 PID 变化检查标准错误、日志权限和 init 重启记录可能是轮转错误导致进程退出修改配置后周期没变配置在进程启动时读取需通过前文方法让 init 启动新实例磁盘已满或/var/log不可写这是 I/O 故障本篇没有实现磁盘空间告警或退避重试本篇轮转的是单个固定文件不支持按日期命名、多个历史备份、压缩、并发写入者、磁盘配额或掉电持久化保证。重命名与新文件位于同一文件系统fflush只将 C 标准库缓冲交给操作系统不等于fsync或掉电保护。如果rename或新活动文件打开失败代码会尽力恢复原路径并继续无法恢复时会退出。当前服务由respawn管理因永久性存储错误退出可能造成重复启动因此这仍是用于实验的实现不应直接当作生产日志系统。十一、总结本次 QEMU 实测中.1达到 1024 字节活动文件为 711 字节备份末尾 tick 98 后活动文件从 tick 99 继续PID 119 保持不变且活动文件中找到重开标记。这验证了正常轮转后服务继续写入活动文件。改名或重新打开失败时的恢复分支尚未做故障注入测试旧备份在多轮轮转中的替换行为也未单独核对。下一篇预告下一篇《服务正常运行同时验证权限限制确实生效》。我们将把服务从 root 运行调整为专用的非特权用户只授予它运行和写日志所需的权限再验证日志仍持续写入、对不必要资源的访问确实受限。具体配置方式会以 Buildroot 和目标 BusyBox init 实际支持的工具为准并通过目标端检查验证而不只依据配置文件推断权限已生效。