Elasticsearch：自定义应用程序的日志记录 - Elastic Common Schema

Posted 2022-08-17 Elastic 中国社区官方博客

在我们的许多开发的应用中，有许多的日志生成。我们可以使用 Beats 或者 Logstash 来收集这些日志，并最终发送至 Elasticsearch。这些日志信息为我们对这些应用的可观则性提供了可能。如果应用生成的日志满足 ECS，那么它将节省我们很多的事情，比如我们无需对日志进行结构化，甚至做丰富等操作。

一个理想的记录日志的设置：

• 应用的日志的输出是以 JSON 形式的
• 日志的结构是 ECS 兼容的
• 使用 logging 库

在我之前的文章 “Beats: 使用 Filebeat 进行日志结构化 - Python”，我展示了如何使用 Filebeat 来收集 JSON 格式的日志。

Why ECS?

采用 ECS 的原因很简单：

• 简单：我们无需额外的解析
• 在摄入日志时，它的格式是预设置好的，而且甚至是预丰富过的
• 人类可读的 JSON 结构
• 可以和 Kibana 中的许多 UI 直接对接，无需创建额外的可视化
• 使用 ECS 在不同的服务及团队中，它可以使得我们创建可以重复使用的 dasboard 及避免 mapping 爆炸
• APM log 相关

示例：Standard vs ECS 日志记录

我们通过如下的的两个小的示例来展示到底什么是 ECS 相兼容的日志记录。

Standard

标准的日志记录示例如下：

app.py

import logging

# Get the logger
logger = logging.getLogger("app")
logger.setLevel(logging.DEBUG)

# Add an ECS formatter to the Handler
handler = logging.StreamHandler()

logger.addHandler(handler)

#Emit logs
for x in range(0, 10):
    logger.debug("Request received from 192.168.0.3")

上面显示了一个典型的 Python 记录日志的方式。运行上面的代码，我们可以看到如下的结果：

$ python app.py 
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3
Request received from 192.168.0.3

显然的上面的输出不利于我们对这个数据进行分析。比如，我们想知道 IP 地址 192.168.0.3 这个地址的更多信息，我们还必须通过 grok 或者 dissect 处理器来结构化上面的信息，然后我们才可以使用 GeoIP 处理器来分析。

ECS

为了能够更加易于我们的方式来分析日志信息，我们可以采用 ECS 相兼容的格式进行输出：

app-ecs.py

import logging
import ecs_logging

# Get the logger
logger = logging.getLogger("app")
logger.setLevel(logging.DEBUG)

# Add an ECS formatter to the Handler
handler = logging.StreamHandler()
handler.setFormatter(ecs_logging.StdlibFormatter())
logger.addHandler(handler)

# Emit logs
for x in range(0, 10):
    logger.debug("Request received from 192.168.0.3", extra="client.ip": "192.168.0.4")

运行上面的代码，我们可以看到如下的输出：

$ python app-ecs.py 
"@timestamp":"2022-08-12T09:47:35.408Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"
"@timestamp":"2022-08-12T09:47:35.409Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"

上面的显示比较不容易看清楚。我们可以拷贝其中的一条记录，并执行如下的命令：

echo '"@timestamp":"2022-08-12T09:47:35.408Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"' | jq

我们可以看到如下的输出结果：

$ echo '"@timestamp":"2022-08-12T09:47:35.408Z","log.level":"debug","message":"Request received from 192.168.0.3","client":"ip":"192.168.0.4","ecs":"version":"1.6.0","log":"logger":"app","origin":"file":"line":15,"name":"app-ecs.py","function":"<module>","original":"Request received from 192.168.0.3","process":"name":"MainProcess","pid":53150,"thread":"id":4372432256,"name":"MainThread"' | jq

  "@timestamp": "2022-08-12T09:47:35.408Z",
  "log.level": "debug",
  "message": "Request received from 192.168.0.3",
  "client": 
    "ip": "192.168.0.4"
  ,
  "ecs": 
    "version": "1.6.0"
  ,
  "log": 
    "logger": "app",
    "origin": 
      "file": 
        "line": 15,
        "name": "app-ecs.py"
      ,
      "function": "<module>"
    ,
    "original": "Request received from 192.168.0.3"
  ,
  "process": 
    "name": "MainProcess",
    "pid": 53150,
    "thread": 
      "id": 4372432256,
      "name": "MainThread"
    
  

从上面的输出结果中，我们可以看出来它含有时序数据最重要的一个 @timestamp 字段。并且，client.ip 也被自动地形成一个对象。log 字段也自动地匹配 ECS 的标准格式。我们通过文章   “Beats: 使用 Filebeat 进行日志结构化 - Python” 所提供的方法，把这个日志摄入到 Elasticsearch，那么它就是一个标准的 ECS 想兼容的日志信息。我们甚至直接可以使用很多的现有的可视化来对数据进行分析。

我们可以针对其它的语言也采用同样的方法来输出日志。请使用相应的库来完成。

定制日志建议

在我们的定制应用中输出日志时：

• libraries > json > just iso8601 timestamp > 任何其它格式的日志
• 记录有意义的信息
• 记录有意义的错误信息
• 你可以选择任何其它的有用的信息来记录，日志在 Elasticsearch 中的存储也不贵，你可以随时删除一些不想要的信息
• 不要记录敏感的信息
• 考虑使用 ILM。你可以参考文章 “Elasticsearch：Index 生命周期管理入门”。
• 你甚至可以考虑使用 frozen indices 来存储日志
• 采用 RBAC (role based access control)。你可以详细阅读文章 “Elasticsearch：用户安全设置”。
• 尽量结构化日志信息，在可能的情况下