您不能拥有的日志/事件处理管道(2019)

让我告诉你我们在我上一份工作中建立的实时日志处理管道，这条管道现在已经不存在了。它处理来自我们的ISP代表居民客户运营的大量嵌入式设备的日志。(我之前写过并展示了此数据集可能带来的一些很酷的WifiDiagstics。)。

最近，我进行了大量关于日志处理管道的对话，数量之多令人惊讶。我可以找到大约10多家已经投入资金、看似成功的初创公司处理日志，大名鼎鼎的云提供商都有一些类似的日志，但人们仍然不满意。它又贵又慢。如果你抱怨，大部分人会告诉你无论如何都不应该使用非结构化日志，而应该使用事件流。

与其对整个不愉快的情况进行调查，不如让我们忽略其他人的痛苦，谈谈什么是有效的。你可能会在某个地方找到与我将要谈论的每个组件类似的东西，但你可能找不到一个合理的价格将所有这些都与良好的性能和超低延迟结合在一起的单一解决方案。在某些地方，你可能会找到与我将要谈论的每个组件类似的东西，但你可能找不到一个合理的价格将其与良好的性能和超低延迟结合在一起。至少，我还没有找到它。我对此感到有点惊讶，因为我不认为我们在做任何创新的事情。显然我错了。

让我们开始吧。下面是我们将要讨论的所有部分的简便易行的图表：

我工作的ISP有一堆我们想要监控的嵌入式Linux设备(路由器、防火墙、wifi接入点等等)。随着时间的推移，这一数字迅速增加，但让我们来谈谈一个不错的整数，比如10万人。起初，我们的开发实验室里有0个，然后可能是10个，最终我们达到了10万个，后来有更多的人。管他呢。让我们和10万人一起工作吧。但请记住，此体系结构对任何数量的设备几乎都是一样的。

(从可伸缩性的意义上讲，它是一个分布式系统，但它也是真正适用于任何数量的设备而不是少数设备的最简单的东西，这使得它与许多分布式系统不同，在许多分布式系统中，如果您不关心可伸缩性，您可以更简单地解决问题。由于我们的日志来自多个来源，我们不能使其成为非分布式的，但我们可以尝试最小化必须处理额外复杂性的部分的数量。)。

现在，这些是我们监控的设备，而不是应用程序、服务或容器之类的。这意味着两件事：我们必须处理很多奇怪的问题(比如编译器/内核错误和硬件故障)，而且大多数软件都是我们不容易控制(或者不想重写)的现成操作系统。

(这里有一个好消息：因为嵌入式设备从头到尾都有所有问题，所以任何适用于我的大量嵌入式设备的解决方案都可以解决您可能遇到的任何其他日志管道问题。如果你幸运的话，你可以省略一些零件。)

这意味着关于事件与日志的辩论有点毫无意义。我们没有控制系统中的所有部分，所以告诉我们忘记日志，只使用结构化事件是没有帮助的。Udhcpd按照它想要的方式生成消息，这就是它的生活。有时内核会恐慌，打印它想打印的任何东西，这就是生活。往前走。

当然，我们也有自己的应用程序，这意味着当它与我们自己的应用程序相关时，我们也可以产生外部结构化事件。我们的团队就日志和事件、结构化和非结构化哪个更好进行了无休止的争论。事实上，只有资金过多的大企业才能负担得起，我们实际上实现了这两种方式，并运行了很长一段时间。

因此，我现在可以一劳永逸地告诉您最终的正确答案：您需要数据库中的结构化事件。

但是您需要能够从非结构化日志中生成它们，一旦您能够做到这一点，那么这些结构化事件究竟是如何生成的(无论是从日志还是直接从结构化跟踪输出)就变得无关紧要了。

但是我们有点超前了。让我们看看我们的流程图，从左到右，一次一个部分。

一些在Linux上从事黑客攻击已有一段时间的人可能知道/proc/kmsg：这就是文件Good old(之前的systemd)klogd从syslogd读取内核消息并将它们压缩到syslogd，syslogd会将它们保存到一个文件中。现在，systemd做着大致相同的事情，但是使用了更多的d-bus和更多损坏的二进制日志文件。啊哼。不管怎么说。当您运行dmesg命令时，它读取相同的内核消息(方式略有不同)。

你可能不知道的是，你可以往另一个方向走。有一个名为/dev/kmsg的文件(注意：/dev而不是/proc)，如果您写入该文件，则会将消息生成到内核的缓冲区中。让我们做那件事吧！为了我们所有的信息！

因为我们希望严格排序程序之间的日志消息。即使您的内核出现恐慌，我们也希望如此。

想象一下，比如说，你有一台运行在嵌入式Linux系统上的电视DVR，每当你去播放特定录制的视频时，内核都会死机，因为你的芯片组供应商讨厌你。假设如此。(假设这种感觉是相互的。)。理想情况下，您希望您的日志中包含用户请求的视频，该视频即将开始播放，我们已打开该文件，我们即将开始将该文件流式传输到专有且有错误(假设)的视频解码器中。砰的一声。惊慌失措。

现在怎么办？嗯，如果您正在将日志消息写入磁盘，那么笑话就落在您头上了，因为我打赌您在每次写入之后都没有使用fsync()。(很久以前，syslogd实际上在每个命令之后执行fsync()。它是疯狂的磁盘研磨，吞吐量非常低。那些日子已经一去不复返了。)。此外，内核会使磁盘驱动程序死机，所以你没有机会在死机后对其进行fsync()操作，除非你进行了更可怕的黑客攻击，比如在死机后引导到第二个内核，这个二级内核的唯一工作就是将消息缓冲区流式传输到一个文件中，拼命希望磁盘驱动程序不是那个死机的东西，磁盘本身没有被烧毁，而且即使你管理写一些磁盘块，它们也是正确的，因为你的文件。

(读完那段话，我突然觉得自己很可怜。在这一点上，我认为我更多的是伤疤，而不是人。)。

内核日志缓冲区位于RAM中的固定大小内存缓冲区中。它默认有点小(几十或几百千字节)，但是如果你愿意，你可以把它变大。我建议你这么做。

就其本身而言，这并不能解决内核死机问题，因为RAM甚至比磁盘更不稳定，而且你必须在内核死机后重新引导。所以RAM不见了，对吧？

曾几何时，您的PC BIOS会在引导时遍历所有RAM并运行内存测试。我记得我那台古老的386DX电脑曾经用我惊人的坚固耐用、改变人生的4MB内存来做这件事。这花了相当长的一段时间。如果你和自己一样是一个勇敢的冒险叛逆者，你可以按Esc跳过它。

现在，内存比以前快了很多，但不幸的是，它变得更大的速度比它变得更快，特别是如果您禁用了内存缓存，您肯定必须在引导时禁用内存缓存，以便编写查看是否有任何位错误所需的非常特定的模式。

所以..。我们不做开机时内存测试，几年前就结束了。如果您重新启动系统，内存将主要包含重新启动之前包含的内容。Theos内核必须知道这一点，并在使用页面时清零页面。(有时内核会变得花哨，在不忙的时候会预置一些多余的页面，这样它就可以根据需要更快地分发零页面。但它总是必须将它们置零。)

因此，当系统重新启动时，页面仍然存在。我们希望发生的是：

内核死机后，系统会自动重新启动。要做到这一点，可以给内核设置一个引导参数，比如"；Panic=1"；，它会在一秒后重新引导内核。(对于终端用户来说，阅读和思考恐慌消息的时间远远不够。这很好，因为：a)在台式PC上，X11会在图形模式下崩溃，所以无论如何都看不到死机信息；b)在嵌入式系统上，通常没有显示器来显示这些信息。(B)在台式机上，X11会在图形模式下崩溃，所以你无论如何都看不到死机信息；b)在嵌入式系统上，通常没有显示器来显示这些信息。最终用户不关心紧急消息。我们的工作是尽快重新启动，这样他们就不会试图通过重新打开设备的电源来帮助您，这确实会丧失您的记忆力。)。(高级用户将使其在零秒后重新启动。我认为Panic=0会禁用重启功能，而不是这样做，因此您可能需要修补内核。我忘了。我们做到了，不管是什么。)。

内核注意到先前的dmesg缓冲区已经在该后台RAM中(由于有效的签名或校验和或其他原因)，并决定追加到该缓冲区，而不是重新开始。

在用户空间中，我们从停止的地方开始日志处理。我们取消捕获在死机之前(因此也包括在内)开始的日志消息！

因为我们将用户空间日志重定向到内核消息缓冲区，所以我们还保留了导致死机的事件的确切顺序。

如果你想让这一切发生，我有好消息和坏消息。好消息是我们所有的代码都是开源的；坏消息是它没有被上传到任何地方，所以没有电池，也没有文档，它可能不太适合你的用例。抱歉的。

用于将用户空间日志发送到/dev/klogd的徽标工具。(它的日志...。对于操作系统..。这是合乎逻辑的..。它能让你的日志在重启后起死回生...。明白了吗？不是吗？哦，好吧。)。这包括两个每个应用程序的令牌桶(突发和长期)，这样失控的应用程序就不会超载有限的dmesg空间。

即使您不执行其他任何操作，每个人都应该在每台计算机上使用PRINTK_PERSISTENT，无论是虚拟的还是物理的。我是认真的。太好吃了。

(注意：改进的空间：如果我们只需将stdout/stderr直接重定向到/dev/kmsg，那会更好，但这并不能像我们希望的那样工作。首先，它不会自动为传入的消息添加应用程序名称的前缀。其次，像printf()这样的libc函数实际上一次写入几个字节，而不是每次write()调用一条消息，因此它们最终会在每行生成多个dmesg条目。第三，/dev/kmsg不支持logos所支持的令牌桶速率控制，这被证明是必不可少的，因为有时应用程序会变得疯狂。因此，我们必须进一步扩展kernelAPI才能使其正常工作。不过，这是值得的，因为在userspace程序打印内容和实际进入内核日志之间，外部用户空间进程会导致不可避免的延迟。这个延迟足以让内核恐慌，并且用户空间消息群会丢失。直接写入/dev/kmsg将占用更少的CPU，保持用户空间延迟不变，并确保在继续之前安全地写入消息。总有一天！)。

(在相关新闻中，这使得所有的syslogd都有点无关紧要。无论systemd做什么，都是如此。为什么我们要把每件事都搞得这么复杂？直接写入文件或内核日志缓冲区。它既便宜又容易。)。

接下来，我们需要将消息从内核日志缓冲区中取出，并将其放入日志处理服务器中，无论该服务器在哪里。

(注意：如果我们执行上面的技巧-将用户空间消息写入内核缓冲区-那么我们也不能使用klogd将它们读回syslogd。这将造成无限循环，并将以糟糕的结局收场。问我怎么知道的。)。

因此，没有klogd->；syslogd->；文件。相反，我们有类似syslogd->；kmsg->；上传程序或app->；kmsg->；上传程序。

什么是日志上载程序？嗯，它可以在消息到达时从内核KMSG缓冲区读取消息，并将它们上传到服务器，可能是通过https。它可能几乎和我最初的原型一样简单，但我们可以做得更花哨一点：

找出我们已经上传了哪些消息(例如，在我们重新启动之前从永久缓冲区)，并且不要再次上传这些文件。

在上传之前记录当前挂钟时间，为我们提供单调时间之间的同步点(默认情况下，/dev/kmsg logs"；microsec自启动起"；微秒，这非常有用，但我们也希望能够将其与"；实时&34；时间相关联，以便我们可以在相关计算机之间匹配消息)。

额外好处：如果日志服务器因网络分区而不可用，请尽量保留该分区之前的最后几条消息，以及该分区恢复后的最新消息。如果网络分区是由客户端引起的-如果您像我们一样从事路由器和WiFi接入点的制造业务，这并不罕见-您真的很想查看连接中断之前的消息。

幸运的是，我们也为此开放了我们的代码。它是用C语言编写的，所以它非常小，开销也很低。不过，我们一直没有拿到奖金功能的代码，运行得很好；我们在最后一刻有点被打断了。

Loguploader C客户端，包括一个用于Debian的rsyslog插件，以防您不想使用/dev/kmsg技巧。

Devcert，这是一个工具(和Debian软件包)，无论安装在哪里，它都会自动生成自签名的设备证书。设备证书由设备(或VM、容器等)用于向日志服务器标识其自身，然后日志服务器可以决定如何分类和存储(或拒绝)其日志。

不幸的是，我们没有做的一件事是修改日志上传客户端以将日志流式传输到服务器。使用HTTP POST和ChunkedenCoding可以做到这一点，但是由于(我认为现在已经修复)基础设施的限制，我们的服务器当时无法接受流式POST请求。

(注意：如果您编写负载平衡代理服务器或HTTP服务器框架，请确保它们可以在所有头文件到达后立即开始处理POST请求，而不是等待整个BLOB完成！则日志上传服务器甚至可以在请求结束之前将字节直接流式传输到下一阶段。)。

因为我们客户端缺少流媒体，所以我们不得不定期上传大量日志，这就需要权衡什么才是一个好的上传周期。我们最终确定了大约60秒，这几乎占据了从消息生成到我们的监控控制台的所有端到端延迟。

大多数人可能认为60秒不算太差。但是我们团队中的一些很棒的人设法将所有其他流水线阶段压缩到总共几十毫秒。所以剩下的60秒(严格地说是在信息产生后0到60秒之间)是有点尴尬的。从一个设备直播到另一个服务器会更好。

因此，好的，我们将日志从客户端重新上传到某种类型的服务器。服务器是做什么的？

这部分既是最简单的部分，也是可靠性最关键的部分。任务如下：接收HTTP POST请求，将POST数据写入文件，然后返回HTTP200OK。任何有任何服务器端经验的人都可以在大约10分钟内用他们喜欢的语言编写这篇文章。

我们有意使这一阶段尽可能地简单化。这是从客户端上有限大小的kmsg缓冲区接受日志并将它们放在某个持久位置的阶段。有实时提醒很好，但如果我必须在延迟提醒和事情变得糟糕时随机丢失日志消息之间做出选择，我将不得不接受延迟的提醒。不要丢失日志消息！你会后悔的。

不丢失消息的最好方法是最大限度地减少日志接收者所做的工作。所以我们就这么做了。它接收上传的日志文件块并将其附加到文件，仅此而已。文件实际上位于与S3或多或少类似的云存储系统中。当我向某人解释这一点时，他们问我们为什么不把它放在一个类似于Bigtable的东西或其他数据库中，因为文件系统不是有点俗气吗？不，它不俗气，它很简单。简单的东西不会破裂。我们团队中的朋友使用结构化事件来制定指标，直接将这些事件流式传输到数据库中，但它总是中断，因为数据库有配置选项，而您不可避免地会错误地设置这些选项，而这些选项在过重的负载下会崩溃，除非您正处于紧急情况中，并且您真的想要查看这些日志，否则您不会发现这一点。在此之前，我们的团队将使用结构化事件来对这些事件进行度量，但它总是会中断，因为数据库中有配置选项，而您不可避免地会将这些选项设置为错误，并且在负载过重的情况下，您不会发现，除非您正处于紧急情况中，并且您确实想要查看这些日志。或事件。

当然，我们使用的文件存储服务是静态加密的，经过严格审核，文件会在N天后自动删除。当你重新组建公司时，你会有一个完整的团队来确保你不会把这件事搞砸。他们会找到你的。最好不要惹恼他们。

我们不得不添加一个额外的功能，那就是身份验证。互联网上的任何人都不能冒充你的设备，向你的日志发送垃圾邮件--至少不需要投入一些工作。对于设备身份验证，我们使用了很少使用的HTTP client-side证书选项和devcert程序(上面链接)，以便客户端和服务器可以相互验证。服务器没有根据证书颁发机构(CA)检查证书，而是像Web客户端通常所做的那样；相反，它有一个包含白名单的数据库，其中包含我们现在允许使用的证书。因此，如果有人偷了设备证书并开始胡闹，我们可以将他们的证书从白名单中删除，而不用担心CRL错误和延迟等问题。

不幸的是，因为我们的日志接收器是一个依赖于内部基础设施的内部应用程序，所以它不是开源的。但老实说，那里真的有很多东西。第一个是用大约150行Python编写的，替换的代码是用稍微多一点的GO行重写的。没问题。

当然，事情并不总是一帆风顺的。如果你是一名ISP，最容易处理的事情就是处理整个街区都被切断的情况，要么是因为停电，要么是因为有人切断了附近的光纤互联网接入。

现在，断开连接对于日志处理来说并不是什么大问题-您没有任何问题。但是重新连接是一件非常重要的事情。现在，您的数万或数十万设备同时重新联机，并且a)它们积累了比平时多得多的日志消息，因为它们无法上传这些消息；b)它们都想同时与您的服务器对话。啊哦。

幸运的是，我们的系统设计得很仔细(呃...。最终是)，所以它可以相当顺利地处理这些情况：

日志上传程序使用回退计时器，因此如果它已经尝试了一段时间的toppload，它上传的频率就会降低。(但是，退避计时器被限制为不超过通常的上传间隔。我不知道为什么更多的人不这么做。对于您的系统来说，在失败情况下两次上传之间等待的时间比在成功情况下等待的时间要长，这是相当愚蠢的。对于日志尤其如此，当事情恢复在线时，您需要立即更新状态。显然，您的服务器有足够的容量以通常的速率处理上传，因为它们通常不会崩溃。抱歉，如果我在这里听起来像是在辩护，但我不得不和几个SRE有过几次这样的争论。我理解为什么限制回扣期限并不总是正确的举措。这是正确的做法。)。

不太明显的是，即使在正常情况下，日志上传器也会在两次上传之间使用随机间隔。这避免了流量高峰，在互联网恢复在线后，恰好60秒后，每个人都会再次上传，以此类推。

日志上传客户端理解服务器现在可以接受请求的想法。它必须，一个。

.