日志里每5次Googlebot抓取，就有1次IP不属于谷歌

摘要：保哥拿自己那台服务器上跑了43天的日志做了一轮体检，结果比预想的难看：访问日志482MB共208万行，而错误日志2.7GB共185万行——行数少了11%，体积却是前者的5.7倍，因为一行里平均塞了5.94条报错。全量数一遍是1097万条报错消息，其中真正需要动手修的那类只有50行。同一份访问日志，数404的四种写法给出两个不同答案；同一台机器上的四份日志，用了四种互不相同的时间格式，其中一份还是另一个时区。最后一个数字最扎眼：日志里声称自己是搜索引擎爬虫的请求有97308条，拿官方公布的IP段逐条比对之后，21.7%的IP根本不属于它，而这两万多次伪装抓取里有20550次拿到了正常的200响应。本文给出把日志从能存变成能查的完整改法，以及一次把自己坑了的测量事故复盘。

先交代背景。这台机器上跑着好几个站，日志按站分文件，从6月19日一路长到7月31日没被切过。保哥原本只想看看某个页面被抓了多少次，结果一头撞进了下面这一串问题。

需要先说明的是，下面这些数字全部来自一台正在对外提供服务的机器，不是实验环境造出来的样本。所以它们不好看——真实环境本来就不好看。如果你手上那台机器从来没被这么翻过，大概率能对号入座其中的大半条。

这篇不讲怎么搭一套日志系统——那类文章网上有的是，装几个组件、贴几段配置。这篇讲的是为什么你现在这份日志查不动，以及每一处查不动分别是哪个决定造成的。

2.7GB的错误日志里，真正的错误有几行？

先看体积。同一个站的两份日志：

错误日志的行数比访问日志少11%，体积却是它的5.7倍。单行平均长度差6.4倍。

为什么一行能有1490字节？抽5万行数了一下每行里出现了几条报错：

5万行里有48747行整整齐齐都是6条。这是因为处理器把一个请求周期内产生的所有报错攒起来，通过一个通道一次性交给服务器，服务器把它们写成了一行。全量数下来，185万行里装着10976226条报错消息。

然后是信噪比。把报错按模板归类，头部长这样：

注意最后一行。前面那些是废弃写法的提示，属于代码风格问题，不影响功能；而最后那条是真的会让功能出错——正则没编译成功，那次匹配就是空的。全量扫一遍，含这条报错的行只有50行。

1097万条消息里，50行是需要立刻处理的。比例是二十一万分之一。同一台机器上的数据库慢日志也是这个形态：931MB的文件，里面绝大多数记录的执行时间都在几毫秒级别。两次撞上同一个规律：日志的体积和它的信息量几乎不相关。

顺便说说磁盘。整个日志目录4904153052字节，而根分区已用7260790784字节——已用空间的67.5%是日志。而且检查了一遍系统的日志轮转配置目录，里面根本没有管这些文件的规则，所以它们从6月19日起就一直在长。本站在日志管理那篇里写过怎么配轮转，这台机器算是活教材：轮转工具装了，配置文件也在，就是没人给这个目录写一条规则。

那1GB躺了40天没人看的文件是什么？

体检还翻出一件更尴尬的事。按体积排，这台机器上最大的三个日志文件是：

中间那个1GB的文件，最后一次写入是40天前，之后再没动过——某次配置调整把输出改到别处了，而这1GB就此留在原地。它不产生任何价值，只是每天参与一次磁盘占用统计。

这类文件在服务器上比想象中常见。它们的共同特征是：曾经有用、后来配置改了、没人记得删。查磁盘占用的时候看见一个眼熟的名字，第一反应还以为它在正常工作。排查磁盘和负载时值得顺手加一步：按最后修改时间排一遍，凡是超过一个月没写入还占着大空间的，先确认它是不是已经被遗弃了。

为什么同一份日志，两种数法答案不一样？

接下来是查询本身。最简单的问题：这份日志里有多少个404？

四种常见写法，跑出来是这样：

三种一致，一种多了12。多出来的那12行是什么？捞出来看了眼，答案挺有意思——

那是有人在做注入探测，把一段构造好的字符串放进了来源地址里，而那段字符串里恰好含有前后带空格的404。

也就是说，攻击者构造的字符串被当成了状态码统计进去。这个误差只有万分之二，看起来无所谓，但它揭示的问题是结构性的：纯文本搜索没有字段概念，它不知道哪一段是状态码、哪一段是别人塞进来的内容。

更麻烦的是按位置取字段这条路也不牢靠。数了一下每行按空格切出来有多少段：

取值一共36种，从10段一直到47段都有。

原因是来源地址和客户端标识里可以含空格，含几个由对方决定。默认的组合格式确实用引号把这两个字段括起来了，但按空格切的时候引号不起作用。所以那个第9段有时是状态码，有时是别的东西——只不过在这份日志里，含空格的字段恰好都排在状态码后面，才让答案碰巧对了。换个日志格式，把客户端标识挪到前面，这个写法就会全线崩掉。

结论很直接：纯文本日志里没有字段，只有看起来像字段的位置。所有基于位置的解析都是在赌对方不往里塞空格，而对方恰恰是最有动机塞空格的那个人。

一台机器上的四份日志，为什么时间格式全不同？

这一条是保哥觉得最离谱的。同一台机器、同一套软件栈，四份日志的时间戳：

四种格式，三种字段顺序，两种时区。想把同一分钟内这四份日志并排看，第一步得写四个解析规则，第二步还得给第三份做八小时的时区换算。

这不是谁偷懒，是每个软件各自沿用了自己的历史习惯。但代价是真实的：关联分析的第一道门槛不是技术，是时间对不齐。

为什么日、月、年的排法会让排序失效？

这里有个后果比看起来严重。关于时间格式，有一份规范专门讨论过排列顺序的价值，原文写的是："If date and time components are ordered from least precise to most precise, then a useful property is achieved."——如果按从粗到细排列，就能得到一个有用的性质。紧接着那句给出了性质本身：这样的时间串可以直接当字符串排序，结果就是时间顺序。

访问日志那个格式正好是反的，最细的日排在最前，最粗的年排在最后。后果就在这份日志里直接撞上了：这43天跨了6月和7月两个月，把月份字段取出来去重排序，得到的顺序是——

Jul，然后是Jun。

字典序里字母l排在n前面，所以七月被排到了六月前面。这份日志里恰好只有两个月份，而这两个月份的字典序和时间序正好是反的。要是有人拿排序去做时间范围筛选，第一条就错了。

而同一台机器上的数据库慢日志用的正是那份规范里推荐的格式，年在最前、带零时区标记。同一台机器上，一份日志遵守了这条规范，另一份没有。

取最近十分钟的日志有多难？

顺着上一条往下试。要从访问日志里取最近十分钟的记录，纯文本能做到什么程度？

因为格式是日在前，而且没法当字符串比较大小，实际能用的只有前缀匹配。匹配到小时这一级还行，匹配到分钟就得把这十分钟的每一分钟都列出来当或条件。实测按小时前缀粗筛，拿回来177行，而想要的是其中一个子集——你要十分钟，只能拿到整小时，剩下的靠自己再过滤一遍。

跨小时的时候更难看：19点55分到20点05分这十分钟，前缀分成两段；跨零点跨月跨年各有各的写法。这类活写一次能忍，天天写就该换方案了。

全文搜索到底慢在哪，结构化又快在哪？

把耗时量出来才好谈方案。482MB、208万行的访问日志上，几个典型查询：

单纯搜一个词并不慢，六百多毫秒。贵的是分组统计：7121毫秒，因为它要把208万行的第9段全部取出来、排序、再合并计数。而这恰恰是分析日志时最常做的动作。

2.7GB的错误日志上跑一次全文搜索是1933毫秒，数一遍报错总条数7203毫秒。都还能忍，但注意这是单次——每换一个问题就要重新扫一遍全文，成本不会因为你刚才扫过而变便宜。

然后是结构化的对照。把同一份日志按字段解析后导入一个带索引的本地库：

接近38秒，比任何一次全文搜索都贵得多。但导完之后：

体积方面也没有想象中夸张：原始日志482MB，导入后的库431MB，比原文还小（因为丢掉了重复的分隔符和固定文本），加两个索引之后涨到533MB，增幅23.7%。

从哪一次查询开始，导入的成本才回本？

这是个能算出准数的问题。一次性成本38247毫秒，之后每做一次分组统计省下7121减124等于6997毫秒。

38247除以6997约等于5.5。也就是说，只要你打算问超过6个问题，导入就是划算的。

而真实排查从来不止6个问题。查一个抓取异常，通常是这样一串：先看总量，再按状态码分组，再挑出404看路径，再看这些路径的来源，再看时间分布，再对比上周同期……六个问题只是起步。

这个算法也给出了反向判据：如果你只想查一件事、查完就走，那就别导。搜一个词六百多毫秒，比等38秒快多了。日常那种"看看某个页面今天被抓了几次"的需求，直接搜就好。

划分很清楚：一次性的问题用搜索，成组的问题用结构化。这条判断不需要任何工具支持，靠脑子里那个5.5就够。

结构化之后能问出什么原来问不出的问题？

速度只是表象，真正的差别是问题的形状。举三个实例，都是这轮实测里真跑出来的。

状态码的全景

124毫秒出来的。其中那个444值得单说，它不是标准状态码，是服务端软件自己定义的一个特殊值，意思是直接关掉连接不给任何响应——通常是被拦截规则命中的请求。9749次意味着拦截规则确实在工作，这个数字只有在按字段分组之后才看得到。

404到底是谁在撞

404最多的三个路径里，头一名是一张图片，206次。接着往下问：谁在请求它？

结果里201次的来源是空的，但有2次带着来源，指向本站的某一篇文章；另有1次来自某图片搜索。这两次带来源的记录直接告诉了保哥答案——那篇文章里引用的图片挂了。

这是纯文本给不了的。搜索能告诉你有206次404，但它不会替你把这206行里那2行带来源的挑出来。而恰恰是这2行有定位价值，剩下204行只是噪声。结构化的价值不在于快，在于让稀有信号浮上来。本站在日志分析工具那篇里做的也是同一件事，只是那次用的是现成工具。

爬虫拿到了什么

50毫秒。这张表对做搜索的人来说信息密度极高：280次撞404说明站内还有死链在被抓，24次500说明有页面在爬虫访问时报了错，2次503说明有那么两个瞬间服务没响应过来。

而这个问题用纯文本几乎写不出来——它需要同时按两个字段过滤，一个在行尾附近，一个在中间，还都可能因为空格而错位。

顺便对比一下另一个爬虫的量：某外链分析工具的爬虫在同一时段抓了22580次，是搜索引擎爬虫的四分之一左右。这类数字平时没人看，但它回答了一个很实际的问题——你的服务器有多少资源花在了对流量没有贡献的抓取上。要不要限速、限到多少，得先有这个数才谈得下去。

那两万次假冒抓取，是我自己量错的吗？

这一节是本文最值得写的一段，因为保哥先把自己坑了一次。

最初的问法是：日志里搜到爬虫标识的有97521行，但按字段限定之后只有33101行，差了2.9倍。当时的第一反应是发现了一个大问题——两万多行里那个标识出现在别的字段里。

结果是自己造的。解析的时候为了省内存，把客户端标识截到了120字符。而移动版爬虫的标识串很长，那个关键词出现在一百五十多字符的位置，全被截掉了。

去掉截断重新跑，真值是这样的：

真实差距只有232行，占0.24%，而不是2.9倍。更好玩的是，被截断那版数出来的33101，几乎正好等于桌面版爬虫的真实数量33105——因为桌面版的标识串只有72个字符，关键词在第26位，没被截到。

这个教训值一整段：当测量工具和被测对象共用同一个假设时，测出来的偏差会伪装成发现。如果没回头验一遍，这篇文章里就会多出一条错误结论，而且它看起来还挺像回事。

去掉自己制造的噪声之后，真实数字是多少

回到正题。搜索引擎官方明确提示过，客户端标识是可以随便写的，给出的验证办法有两条：一条是反查域名再正查回来对比，另一条是拿官方公布的地址段清单比对。保哥用的是第二条——把官方那两份清单下载下来，一共304个网段，逐条做地址段匹配。

用的清单文件生成时间是2026年7月30日，也就是跑这轮实测的前一天。结果：

每五次自称是它的抓取，就有一次不是。

真假两边的分布形态完全不同，这一点比比例本身更有说服力：

• 真的那批高度集中：排前三的地址加起来占了98.5%，头一个地址就占52%。
• 假的那批高度分散：一共10464个不同地址，最多的那个也才1411次。

再看假的那批在抓什么，答案就更清楚了：排第一的路径被请求了9846次，那是一篇讲某个内容管理系统注入漏洞修复的文章。披着爬虫的外衣，去找漏洞相关的页面，意图不用猜。而且这些请求里有20550次拿到了正常的200响应——也就是说，本站现有的拦截规则基本没拦住它们。

还有一条自曝：假冒名单里出现了这台服务器自己的地址，25次。多半是某个本机脚本顺手带了这个标识去请求自己的站，属于自己伪装自己，无害但很滑稽。

识别办法本站在拦爬虫怎么不误伤那篇里写过，这次算是给那套方法补了一组真实数据。各类智能体爬虫的识别本站也有专门一篇。

为什么八成的来源字段是空的？

还有一个数字值得放在这里，因为它决定了你能不能追踪流量来路：208万行里，来源字段为空的有1794441行，占86.1%；客户端标识为空的有12368行。

八成六听起来吓人，但这是正常的。直接输地址访问、从加密页面跳到本站、以及大量爬虫都不带来源。真正的问题不是比例高，是很多人不知道这个比例，然后拿剩下那14%去做归因，还以为覆盖了全站。

这也解释了前面那张404图片的例子为什么难得：206次请求里只有2次带来源，占不到1%。能定位问题的那两行，恰好落在最稀有的那个分组里——用纯文本翻，很可能翻到第五十行就放弃了。

顺带一提，队列那套东西在这里也用得上。如果你的应用要把日志实时送到别处，中间挂一个队列比直接写远端可靠得多——保证消息不丢不重那篇讲的取出转存、幂等、死信这三件事，换到日志投递场景是完全一样的。日志量大、允许短暂积压、丢了很难补，正好符合该上队列的判据。

日志该怎么收才不用回头返工？

把上面每一处坑对应到一个改法，就是这张表：

前三条最省力，因为它们只改一处配置。服务端软件自带一个转义参数，把它打开之后所有不合法字符会被转义，输出的每一行就是一个合法的结构化对象。不用装任何额外组件，改一行配置，字段错位问题当场消失。

加请求标识那条是收益最大的。四份日志时间格式各异这件事，本质上是没有一个共同的连接点；给每个请求生成一个唯一串，服务端日志、应用日志、慢查询记录里都带上它，关联就从对时间戳变成了搜一个串。这是整套改造里最值得先做的一步。

字段该有哪些，不用自己拍。有一份被广泛采用的通用字段规范，它的说法是定义一组公共字段，目的是让来自不同来源的事件数据能够被一起分析和关联。照着它的命名走，将来换任何一套分析工具都不用重新映射。

要不要上一整套采集分析栈？

这是个很实际的问题。市面上标准答案是采集器加处理器加存储加界面，四个组件起步，中间可能还要加一层缓冲。

保哥的判断是先看你有几台机器。单机的话，把格式改对、加上轮转，需要分析时导进一个本地库——就是本文实测那套，38秒一次，够用得很。多机才真正需要集中收集，因为那时候的痛点变成了同一个请求的痕迹散在几台机器上，人肉登录挨个查是不现实的。

如果决定要上，有个次序问题值得提醒：先把格式改对再上采集，不要反过来。采集组件本身有很强的解析能力，能把非结构化的行拆成字段，于是很多人就懒得改格式了，直接靠采集端的规则去解析。这一步走错，后面每加一台机器、每换一种日志，都要再写一套解析规则，而且规则写错了不会报错——它会安安静静地把字段拆歪，让你在错误的数据上做分析。

把源头改成结构化只要一行配置，采集端拿到的就是现成字段，一条解析规则都不用写。一行配置和一堆规则之间，选前者。

判据可以更简单：当你需要同时打开两台以上机器的日志才能回答一个问题时，就该集中了。在那之前，格式和轮转做对，收益已经拿到八成。而且格式这件事越早做越好——改配置只影响之后的日志，已经写下去的那482MB是没法追溯改格式的。

这些数字对独立站的抓取预算意味着什么？

把视角切回搜索。前面那张爬虫状态码表里的三个数值得单拎出来：280次404、24次500、2次503。

官方文档里对抓取预算的说明提到过，服务端持续返回错误会让抓取速度下降。大站抓取预算管理那份文档把这个机制讲得很细，核心是抓取速度会根据站点的响应情况自动调整。所以那24次500不只是24个页面没被抓到，它同时在往下压整个站的抓取速度。

而这三个数在纯文本日志里基本查不出来，因为它需要同时按标识字段和状态码字段过滤。查不出来，就等于不存在——很多站的抓取问题不是没发生，是没人有能力看见。本站关于从日志里挖爬虫行为写过完整的方法，前提都是你的日志得先能按字段查。

反过来也成立：那486次301同样值得看一眼。爬虫每撞一次跳转，就要多发一次请求才能拿到真正的内容，这部分开销直接从预算里扣。数量不大，但如果某天这个数突然涨起来，通常意味着有一批链接指向了旧地址。这个信号只有在按爬虫加状态码两个维度分组之后才浮得出来，而这正是前面那张表花50毫秒就能生成的东西。

还有那两万次伪装抓取。它们对搜索本身不直接产生影响，但会污染你的数据：如果你用日志统计爬虫抓取量，那这两万次会被算进去，让你以为抓取覆盖比实际好得多。21.7%的虚高，足以让一份抓取报告得出相反的结论。

最后一个容易被忽略的点：默认格式里没有耗时字段。这意味着你没法从日志回答哪个页面响应最慢这个问题，而响应速度直接关系到同样时间里能被抓走多少页。日志格式该怎么配本站写过一篇，那里面列的字段清单可以直接照抄，其中耗时那两个字段是本文最想强调的。加它的成本是改一行配置，不加的成本是这个问题永远查不了。

常见问题解答

问：改成结构化格式，会不会让日志变大很多？

会大一些，因为每行都要重复字段名。按本文这份日志估算，结构化之后单行大概涨三到五成。但这个代价换来的是不用再写解析规则，而且体积问题该由轮转和压缩解决，不该靠牺牲可读性来省。顺带说，服务端软件的日志指令本身就支持带压缩写入，开了之后落盘的是压缩块，可以随时解压查看，体积能压下去一大截。

问：一行塞六条报错，是配置问题还是没救？

那是服务端把应用通过标准错误通道传回来的内容整体记成了一行，属于两个软件之间的接口设计，改不了。真正的解法是让应用自己写日志：应用层有完整的上下文，能给每条报错单独一行、带上请求标识和堆栈。让服务端去转记应用的报错，本来就是权宜之计。

问：只有几百兆日志，有必要折腾吗？

按本文那个回本点算，只要你会问超过6个问题就划算。但更实际的建议是分两步：格式和轮转现在就改，成本是改两行配置；导入分析等到真需要时再说。格式这件事的特殊性在于它不能追溯——今天不改，今天写下去的日志就永远是查不动的那种。

问：判断爬虫真假，用地址段比对还是反查域名？

两个都是官方给的办法。地址段比对适合批量离线分析，一次下载几百个网段就能把整份日志跑完，本文那21.7%就是这么算的；反查域名适合在线实时判断，但每次要走一趟域名解析，量大时开销明显。要注意地址段清单是会更新的——本文用的那份生成于跑数据的前一天，如果拿一份半年前的清单去比，误判率会明显上升。

问：请求标识具体怎么加？

服务端软件通常有内置变量能生成一个唯一串，把它写进日志格式，同时通过请求头传给后端，应用再把它写进自己的日志和错误信息里。这样一个请求在几份日志里就有了同一个锚点。改动量不大，但它是把多份日志真正串起来的唯一办法，比对时间戳可靠得多——尤其是在时间格式还各不相同的情况下。

问：那两万次伪装抓取要不要拦？

先分清目的。如果目的是保护服务器，那按行为拦比按标识拦有效得多，因为标识本来就是随便写的；如果目的是让统计数据干净，那不用拦，在分析时按地址段过滤掉就行。本文实测里那批伪装请求有20550次拿到了正常响应，说明现有规则没起作用，但它们的总量占全部请求不到1%，对服务器压力有限，优先级可以往后排。

问：这套体检多久做一次合适？

按季度就够，因为它查的是结构性问题，不是当天的异常。一次完整体检大概半小时，动作是固定的六步：看各文件体积和最后写入时间、按模板归类报错取头部、抽样数每行的字段数、对照四份日志的时间格式、跑一次爬虫真假比对、最后看爬虫拿到的状态码分布。本文这一轮就是这么跑下来的，六步里有五步都发现了问题——所以第一次做的时候不用担心找不到东西。

问：错误日志里那50行真问题，怎么才能不被淹没？

靠分级和分流，不靠翻。把废弃写法这类提示在应用层就关掉或者单独写一个文件，让错误日志里只留真正的错误；再给关键错误配告警，让它主动找你。本文那50行分布在一个多月里，最密集的一天有30条——如果配了告警，那天就该收到通知，而不是一个月后在做体检时才发现。

权威参考资料