一、先聊聊日志写入这事有多头疼

写日志这件事,很多开发者一开始都看不上,觉得不过是把几句文本往文件里一扔,有什么难的?等真的跑到线上,尤其是日志一秒钟几万条、几十万条的时候,你就会发现,原本轻飘飘的一句话突然变得像背着一台冰箱在跑步。程序响应变慢,CPU忽高忽低,偶尔磁盘报警,最后查来查去,问题往往就出在“写文件”这个看似最简单的动作上。

这里面的关键原因不复杂:磁盘的写入速率是有物理上限的,再快的SSD也扛不住频繁的小数据写入。每写一条日志,操作系统可能要经过用户态、内核态、设备驱动程序,然后在文件系统里来回折腾。如果业务进程总是傻傻地等着这个流程走完再继续干活,那延迟自然就上来了。尤其是日志和大规模并发搅在一起时,成千上万的请求都堵在写文件这个路口,系统不卡才怪。

在真实的应用场景里,日志不只是给人看的,很多时候还要拿去分析,比如订单日志、支付日志、用户行为日志。这些日志量很大,但大多数都不是必须立刻落盘的。这就给了我们调优的空间——能不能把“马上写”变成“攒一攒再写”,把“同步等结果”变成“交完就走”。这就是异步文件IO要解决的问题。

二、同步写日志为什么慢

2.1 磁盘最讨厌零碎的小请求

你可能会想,现代磁盘技术不是挺厉害吗?NVMe固态硬盘读起来都是几GB每秒,怎么还会被几条日志难住?这里要注意,顺序写和随机写是完全两回事。日志文件通常是在文件末尾追加,属于顺序写,按理说并不太慢。真正的坑在于“频率”。哪怕你只写几十个字节,也要走一次完整的写路径。就像敲键盘,每个字都要抬手再落下,频率太高,手指都会抽筋。操作系统和硬盘也很烦这种高频小包,它们更愿意接收一大块连续数据,一次搞定一整块区域。

2.2 同步写法带来的连锁反应

我们先看一个最普通的Erlang同步写例子:

%% 同步写日志:调用方必须等这句执行完才能往下走
write_log_sync(Fd, Msg) ->
    ok = file:write(Fd, Msg).

很简单吧。但正是这一句,会让调用方卡在写入函数上。正常情况下这没什么,但日志量一大,每次写都占用几毫秒甚至几十毫秒,所有请求都会跟着排队。你说可以把文件打开着不关,反正只写一次。可问题不是打开次数,而是每次写入都是一次系统调用,都会等待磁盘响应。在高并发下,哪怕只是几毫秒的阻塞,放大几百倍就是灾难。

Erlang是一门并发能力很强的语言,它的进程很轻量,适合大量并发的场景。但轻量进程不代表可以无限等待IO。如果你让每个进程都直接去写同一个日志文件,除了阻塞,还会互相争抢文件句柄,造成锁等待,性能进一步下降。所以需要改变策略,把写文件这件事从业务请求中挪出去。

三、把写文件变成异步的几种思路

3.1 单写者模式:专人干专事

异步的核心思想很简单:让业务进程只负责生成日志,把写盘工作交给另一个专门的角色。这个角色在Erlang里可以用一个独立的进程来扮演。所有业务进程都往这个专门进程发消息,发完就继续干活。这个专门进程把消息攒在消息队列里,按自己的节奏写进文件。这样,业务进程不再关心磁盘速度,日志进程也能把零散的小日志合并成几个大块再写,效率会高出一截。

这就像食堂打饭窗口,所有学生把饭盆放在台子上就走了,师傅有空再收,而不是每个人都要等师傅递手里。你想想,是不是快多了?

3.2 简单版异步写入雏形

我们先看一个最简单的异步日志进程:

%% 一个非常简单的异步写日志进程
log_loop(Fd) ->
    receive
        {log, Msg} ->
            file:write(Fd, Msg),
            log_loop(Fd);
        stop ->
            file:close(Fd),
            ok
    end.

启动它:

%% 启动日志进程
{ok, Fd} = file:open("app.log", [append]).
Pid = spawn(fun() -> log_loop(Fd) end).

然后不管哪个业务进程,想写日志就发一条消息:

%% 业务进程只发消息,不等结果
Pid ! {log, "hello log"}.

这段代码虽然简单,但已经带了一点异步的味道。发送消息的进程不会因为写磁盘而阻塞。不过它还比较粗糙:没有批量处理,没有定时强制刷盘,也没有错误恢复。真实生产环境需要更完善的方案。

3.3 聊聊Erlang的延迟写机制

Erlang的文件模块里,有一个很实用的选项叫延迟写。它的作用是把小写入缓存起来,等攒到一定字节数,或者文件句柄关闭时,才真正交给操作系统。配合上单写者进程,效果会更好。它相当于给你的日志文件加了一个“蓄水池”,让水一股一股地往外流,而不是滴一滴流一滴。

使用方式很简单,就在打开文件时加上参数:

%% 打开文件时启用延迟写
{ok, Fd} = file:open("app.log", [append, raw, delayed_write]).

延迟写这个选项在底层做了不少事。它可以设置两个参数:延迟写入的数据大小和延迟时间。当写入的数据大小超过阈值,或者时间超过设定值,数据才会真正进入操作系统。这个机制能极大减少小文件写入的次数,尤其适合日志这种高频追加型数据。不过需要提醒一下,延迟写会改变写入的语义。当写入函数返回ok时,数据只是进了缓冲区,不保证已经落盘。所以对日志这种允许少量丢失的场景,它是很合适的;而对那种要求一条都不能丢的重磅数据,就得结合刷盘操作或者另找方案了。

四、实战:一个可靠的异步日志写入器

4.1 用gen_server把细节封装好

直接写一个接收循环能跑,但生产代码最好还是用Erlang/OTP的通用服务器框架。它的好处是自带状态管理、超时处理、优雅关闭,还有一套清晰的回调结构。我们把它封装成一个日志服务,对外只暴露两个接口:一个写日志,一个停止。

下面的模块就是我们这个异步日志写入器的完整实现:

%% async_logger.erl
%% 一个简单的异步日志写入器
%%
%% 核心思路:
%% 所有调用方把日志消息丢给这个进程,
%% 然后立刻干自己的活,写磁盘的事情交给它慢慢处理。
-module(async_logger).
-behaviour(gen_server).

-export([start_link/1, log/2, stop/0]).
-export([init/1, handle_call/3, handle_cast/2, handle_info/2, terminate/2]).

-define(FLUSH_INTERVAL, 5000).   %% 最多等5秒必须强制写一次
-define(FLUSH_THRESHOLD, 100).   %% 攒够100条就写

start_link(FilePath) ->
    gen_server:start_link({local, ?MODULE}, ?MODULE, FilePath, []).

%% 对外接口:只管发消息,不等待写入结果
log(Level, Msg) ->
    gen_server:cast(?MODULE, {log, Level, Msg}).

stop() ->
    gen_server:stop(?MODULE).

init(FilePath) ->
    %% raw模式跳过虚拟机自己的缓冲,减少拷贝
    %% delayed_write让操作系统帮忙攒着,等量够了再落盘
    {ok, Fd} = file:open(FilePath, [append, raw, delayed_write]),
    %% 安排一个定时器,到时间就检查一下有没有积压日志
    timer:send_after(?FLUSH_INTERVAL, flush),
    {ok, #{fd => Fd, queue => queue:new(), count => 0}}.

handle_cast({log, Level, Msg}, State = #{fd := Fd, queue := Q, count := C}) ->
    Line = io_lib:format("[~s] ~s~n", [Level, Msg]),
    Q1 = queue:in(Line, Q),
    C1 = C + 1,
    State1 = State#{queue := Q1, count := C1},
    %% 只要攒够一定数量,就立刻批量写
    {noreply, maybe_flush(State1)};

handle_cast(_Other, State) ->
    {noreply, State}.

%% 定时器到点,不管攒没攒够,都尝试写一次
handle_info(flush, State) ->
    {noreply, flush_now(State)};

handle_info(_Other, State) ->
    {noreply, State}.

%% 清理资源
terminate(_Reason, #{fd := Fd}) ->
    file:close(Fd),
    ok.

%% 攒够情况下,把队列全部取出,拼成一个大块写出去
maybe_flush(State = #{count := C}) when C >= ?FLUSH_THRESHOLD ->
    flush_now(State);
maybe_flush(State) ->
    State.

flush_now(State = #{fd := _Fd, queue := Q, count := 0}) ->
    State;  % 没有日志要写,直接返回
flush_now(State = #{fd := Fd, queue := Q, count := C}) ->
    Lines = queue:to_list(Q),
    Data = iolist_to_binary(Lines),
    case file:write(Fd, Data) of
        ok ->
            State#{queue := queue:new(), count := 0};
        {error, Reason} ->
            %% 写失败时,这里可以加入自己的告警逻辑
            io:format("write error: ~p~n", [Reason]),
            State
    end.

这段代码虽然只有七十多行,但把异步、批量、定时刷新、优雅关闭都照顾到了。我们来拆开看。

4.2 队列是怎么攒起来的

这里用队列模块在内存里维持一个先进先出的队列。每来一条日志,先拼好格式,然后塞进队列尾部。当队列里的数量达到100条时,就触发一次批量写入。批量写入时,把队列全部倒出来,通过合并函数拼成一个二进制大块,再调用一次写入函数。一次写一大块,比一百次小写要快得多。

使用延迟写后,你会发现写入的次数变少,但每次写入的量变大了。这是操作系统层面的优化,它知道这批数据是连续的,可以一次性排好队。不过要注意,即使启用了延迟写,我们自己的队列依然是需要的,因为它能控制日志进程的处理节奏,并且让我们可以批量拼接成一个二进制块。

4.3 怎么在业务代码里使用

使用方式非常简洁:

%% 在业务代码里这样使用
{ok, _Pid} = async_logger:start_link("logs/app.log"),
async_logger:log(info, "用户登录成功"),
async_logger:log(error, "数据库连接超时"),
async_logger:stop().

因为对外接口发送的是一种不等待回复的消息,所以它永远不会阻塞调用方。即使日志进程正在写一个非常大的块,业务进程也感觉不到延迟。这正是我们想要的效果。

五、适合哪些场景,又有哪些利弊

5.1 典型应用场景

异步日志写入适合日志量大、实时性要求不高、可以容忍少量丢失的场景。比如游戏服务器的行为日志,玩家每一次操作都产生一条记录,一天上亿条,没必要每条都即时落盘。再比如推荐系统的曝光日志,广告点击日志,还有监控系统的指标日志,这些都是高吞吐、低单个价值的数据。

另外,如果业务系统本身要求低延迟,不能因为写日志而拖慢接口响应,异步写就是你最好的朋友。常见于电商平台的订单跟踪、支付平台的风控记录。这些场景里,日志是事后分析用的,晚几秒也不碍事。

5.2 优点有哪些

好处首先是业务不阻塞。日志进程承担了所有等待时间。其次是磁盘效率高,因为批量合并了小块写入。再次是代码结构清爽,业务模块不用关心怎么打开文件、怎么处理IO错误。还有一个额外的好处,日志进程可以集中做格式化、脱敏、过滤这些预处理,非常灵活。

5.3 缺点也要心里有数

缺点最明显的就是数据丢失的风险。如果进程或机器突然崩溃,内存里积压的日志可能还没来得及写就没了。第二个是用内存换性能,队列攒得越多,内存压力越大。如果日志量持续大于磁盘吞吐,队列会无限增长,甚至把内存耗尽。第三个是排查问题变难,如果日志进程本身出了故障,调用方完全感知不到,容易造成日志静默丢失。所以需要一定的监控和告警。使用下来,我会把它定位成“够用且高效”,而不是“绝对可靠”。

六、调优路上需要注意的坑

6.1 别让日志进程一个人扛太多

所有日志都经过一个通用服务器进程,等于把压力集中到一个点上。如果业务量实在太大,可以考虑分片写入,比如按模块或按机器配置多个日志进程,每个进程管一个文件。这样既分担压力,也避免一个进程的消息队列暴涨。

6.2 监控积压情况

一定要给日志进程加上监控。最简单的做法是查看每个进程当前积压的消息数量,通过这个值判断是否出现了写入瓶颈。如果队列一直增长,说明写入速度跟不上生产速度。这时候你要么增加日志进程,要么调大延迟写入的触发字节数,要么提醒业务方降低日志输出频率。

6.3 刷盘策略不是越勤越好

很多人一看日志延迟写就慌,怕丢数据,于是每写一条就强制刷盘。这其实又回到了同步写的老路,性能损失严重。你要根据自己的业务容忍度来定。如果允许丢几秒钟的日志,那就延长定时刷新间隔;如果很不允许丢,那就得考虑同步写加崩溃恢复方案,或者用专门的日志搜集系统。

6.4 文件句柄和权限要提前规划

日志文件会不断增长,长期运行可能把磁盘撑满。建议开启日志滚动,比如按天拆分,或者限制单个文件大小。操作系统对打开文件的数量也有限制,所以不要打开一个文件就一直不关,要记得在进程退出时清理。另外,需要保证日志目录有足够的磁盘空间,否则写入失败时要有对应的告警。

6.5 错误处理别偷懒

在上面的代码里,写失败只是打了个日志。生产环境应该至少做到:写失败时记录失败条数,或者把队列转存到备用位置。另外,文件句柄被外部因素弄坏时,要考虑自动重新打开文件。这些细节决定了你的日志系统在极端情况下是优雅降级还是直接沉默。

七、总结

一句话总结:在Erlang里做大规模日志写入,核心不是追求一条不丢,而是找到性能和可靠性的平衡点。异步文件IO不等于完全不等待,而是把等待从每个业务请求里拿出来,集中到一个地方进行处理。用单写者进程把零散的写请求串起来,配合批量写入和延迟刷盘,就能用很低的成本支撑每天上亿条日志。

Erlang的并发模型天然适合这种“消息驱动”的设计。你只需要把日志当作一种普通消息,交给一个尽职尽责的“慢吞吞但稳妥”的进程,然后放心去处理真正重要的事情。如果你正在构思自己的日志模块,不妨从上面的代码开始,逐步加上监控、滚动和容错,慢慢打磨成适合自己业务的工具。