4.1 调用日志:CLS 全量留痕

场景:grep 服务器日志的时代该结束了

网关上线第一周,客户反馈“接口偶尔慢”,我们登服务器 grep access log,半小时看不到所以然——并发请求的日志交织在一起,耗时字段是平均的,错误与正常混排,两台机器还要分别登。这件事让我们下定决心把调用日志做成结构化数据全量入库,平台就是日志服务 CLS(文档入口 cloud.tencent.com/document/product/614)。

需求定得朴素:每次调用一条记录,字段含请求 ID、appkey、接口、状态码、耗时、来源 IP、是否命中限流与缓存,全量保留,任意组合查询。别小看“全量”二字:审计场景里采样日志等于没有日志,出纠纷时缺的那一条恰好就是关键证据。

旧方案的第二个毛病是定位慢。客户说上午十点那笔失败,我们要登两台机器、按时间切日志、按关键词过滤、再人肉对账,整套流程四十分钟起步。换成结构化日志后,同样的事情在控制台点三下,十秒出结果。这个效率差才是推动全量入库的根本动力。

字段设计是另一场争论。初版我们只存了状态码和耗时,排障时发现永远缺一个字段,反复补字段重跑采集。后来定了规矩:日志字段分三层——标识层(请求 ID、appkey、接口、时间戳)、链路层(上游耗时、下游耗时、缓存命中、限流结果)、业务层(错误码、客户编号、渠道)。三层各管一段,新增需求先归层再开发,字段膨胀才算刹住车。

方案:异步批量投递

日志投递的第一原则是绝不能阻塞主链路。同步写日志等于给每个请求加网络耗时,压测直接掉两成 QPS。方案是进程内的异步批量队列:请求结束时把日志对象扔进队列,响应立即返回;后台挂在 PHP 的 register_shutdown_function 里批量发送,攒满 200 条或超过 500 毫秒即 flush:

设计点 选择 原因
投递方式 异步批量 不阻塞主链路
批大小 200 条或 500 毫秒 延迟与成本平衡
失败策略 本地落盘待补 不丢日志
保留时长 90 天热存 审计与排障够用
敏感字段 脱敏后入库 合规要求

批大小的选择过程值得记录。最初拍脑袋定为 500 条,结果低流量时段一条日志要等几分钟才入库,排障时日志还没到,时针都绕了一圈。改成 200 条加 500 毫秒双触发后,最长延迟不超过一秒。批量系统的两个触发条件——数量与时间——缺一不可,只有数量触发会在低峰期积压,只有时间触发会在高峰期低效。

投递可靠性还分级保证:普通日志允许极端情况下丢失(反正还有下一跳的备份),但审计级日志(鉴权拒绝、熔断触发)必须落盘成功才返回,必要时宁可牺牲一点主链路耗时也要留痕。不是所有日志都值得同样对待,分级保障让珍贵资源用在关键时刻。

配置:批量投递骨架

实现只需一个投递类与 shutdown 钩子。CLS 侧提前建好日志主题,字段索引打开,查询秒出。这段代码跑了两年,至今稳定:

<?php
// 日志投递器(骨架)
class LogShipper
{
    private array $buffer = [];
    private float $lastFlush = 0.0;

    public function push(array $record): void
    {
        $this->buffer[] = $record;
        if (count($this->buffer) >= 200
            || (microtime(true) - $this->lastFlush) > 0.5) {
            $this->flush();
        }
    }

    public function flush(): void
    {
        if (empty($this->buffer)) return;
        try {
            $this->cls->upload($this->buffer);
        } catch (\Throwable $e) {
            file_put_contents('/var/log/gw-fallback.log',
                json_encode($this->buffer), FILE_APPEND);
        }
        $this->buffer = [];
        $this->lastFlush = microtime(true);
    }
}
register_shutdown_function([$shipper, 'flush']);

失败兜底很关键:CLS 网络抖动是常态,落盘补投脚本每小时扫一次 fallback 文件重投,日志不丢是我们的承诺底线。敏感字段(如参数里的手机号)入库前先过脱敏函数,正则匹配替换成星号,合规不留死角。

索引配置是另一门学问。主题建好后,哪些字段建索引需要想清楚:建少了查不动,建多了写入成本和存储都涨。我们的实践是标识层与链路层全建索引,业务层按查询频率选建,长期不查的字段只存不引。分区按天切,查询默认带时间范围,这些都是用账单换来的经验。

踩坑:三条与性能有关的教训

第一个坑是 shutdown 阶段的超时。PHP-FPM 的 shutdown 钩子有时间上限,批量投递若赶上 CLS 慢响应, Worker 没法及时回收,高并发下 worker 数暴涨。修复是投递加 100 毫秒超时,超时即落盘走补投,主进程绝不多等。第二个坑是内存:buffer 在请求内是局部的,但单条日志字段多时 200 条积压可占数 MB,把批大小调到 100 条后内存稳定。这两个坑的共同教训是:旁路系统必须有明确的资源上限,否则旁路会反噬主链路。

第三个坑是日志量带来的成本。全量日志第一个月就写进几十 GB,CLS 账单看得肉疼。优化两手抓:索引只建需要查询的字段,明细字段不建索引改按需采集;第二个是分级存储,热数据主题存 30 天,冷数据在 CLS 里直接投递到对象存储归档(第 5.4 节有成本账)。优化后日志成本降了四成,排障能力一分未损。

查询:三条常用检索式

日志入库只是开始,会不会查决定它的价值。客服找某客户某时段的所有调用,按 appkey 加状态码过滤再按接口聚合,一秒出结果。排障定位慢请求,按 trace_id 精确搜,整条链路的每个阶段耗时一目了然。周报的 TOP 慢接口,按接口分组求平均耗时降序取前二十,固定成报表,客服、运营、开发各取所需。索引建在 appkey、interface、status、trace_id 上,其余字段随查随建。

检索式也有坑:第一次写分析语句没加时间范围,全表扫描直接超时;还有一次用通配符开头匹配,索引失效。查询语法接近 SQL 但有差别,分组的字段必须建索引否则报错。这些细节写进团队手册后,新人查询不再踩雷。

脱敏要趁早。我们有过一次惊险:某客户把身份证号拼在 URL 参数里,日志原样入库,审计时才冒冷汗。事后在入口层就做参数脱敏,手机号、身份证、银行卡正则全覆盖,库里的数据天然干净,比事后清洗省心一百倍。

日志的二次价值

日志基建完成后,好东西接踵而来。客服同学查调用记录不用再找技术,自己在 CLS 里按 appkey 加时间搜索;客户报障时我们按请求 ID 一秒定位;周报里的 TOP 慢接口、TOP 错误接口全自动出表。日志系统从成本中心变成了整个公司的运营数据底座,这也是可观测性的核心价值:同一份数据,服务所有人。

另一个副产品是客户自助排障门户。我们把脱敏后的调用明细开放给客户自己查(配额内可查自己的调用,鉴权隔离严格),客服工单量直接降了四成。客户能看到自己的调用记录与错误原因,很多疑问在自查阶段就消解了。开放数据比解释数据更省力,这个认知让我们的客服体系重新设计了一遍。

小结

调用日志三要素:全量不采样、异步不阻塞、失败不丢失。CLS 批量投递加落盘补投的组合,用很少的代码换来整个公司的排障效率提升。成本用分级存储控住,敏感字段脱敏入库合规。如果整个网关只做一件基础设施的事,做日志。

最后给一个落地的先后建议:先上全量日志跑一周,让所有人体验“能查”的甜头,再推动脱敏与分级存储的成本治理。先享受价值再付出成本,团队配合度会高得多。

日志还有个经常被低估的价值:它是产品决策的依据。我们按接口的调用量与错误率出周报,直接影响了下个季度的优化优先级,比开需求评审会争吵高效得多。日志不是运维的私产,它是全公司的数据资产。

另送一条成本技巧:CLS 的索引只开高频检索字段(appkey、接口、状态码、TraceID),低频字段不开索引。这一步把日志费用又压了三成,检索速度几乎无感。

再补一句日志筛选的纪律:排查问题时先按时间与 TraceID 缩小范围,再按接口下钻。我们在控制台存了五组常用检索语法,值班同学直接复用,平均一次排障的检索语句从手写两分钟变成点一下。工具的成熟度,往往体现在省下的那两分钟里。

延伸阅读