如何设计日志内容
2023-03-09
本文主要为需要进行软件开发的读者提供一些经验和建议。
面向读者
- 需要进行软件开发的
程序员
- 需要所开发系统进行整体把控的
软件工程师
1. 有关日志的基本讨论
在介绍如何设计日志内容前，有以下几个问题需要进行一些简单讨论。
本文的全部内容都基于以下这些讨论来编写。
1.1 为什么要输出日志？
答：为了定位「问题」。
有人认为，系统在运行时如果遇到运行时错误时，本身编程语言或者虚拟机层面就会抛出错误，并且会标记具体的代码行号，所在函数等。并不需要额外去输出日志。也有人认为，系统在上线前，就已经经过详细的测试，所有的处理都已经被检验过，没有必要再在日志中输出相关内容。还有人认为，系统上线后出问题还是自己去负责修复，别人根本也不会去看日志，因此输不输出日志都无所谓。
这些想法都是比较片面的。
我们提到问题，不仅仅是系统报错，也可以是和设计不符的处理过程，甚至可能是用户不肯承认所做的操作而寻找的证据。其次，虽然系统在上线前「理应」被完整地测试，但测试工作本身也可能有出错，有遗漏。如果去要求测试100%没有疏忽的话，不如去要求开发100%没有Bug来的更加直接。最后，开发一个系统的工作并不仅仅只有开发，测试、运维甚至后续运营，好的日志不仅为自身开发带来便利，对其他岗位也有帮助，可以提高团队的整体运行效率。反过来，其他岗位在反馈问题时，如果有日志可查可附带，对开发本身也能带来极大的便利。
因此，无论一个系统多么完美，是否被详细测试过，输出日志都是必不可少的工作。
1.2 日志输出了给谁看？
答：「所有」与这个系统相关的人，都需要查看全部或者部分日志。
有人认为，日志只是自己开发调试，以及后续对线上Bug调查时自己看的。「反正代码最后都是自己来改」，那么其他人不需要看，也没必要看。
这个想法也是错误的。
和「编写代码除了自己能看懂，也要让别人也能看懂一」样。如果说代码仅限开发岗需要看的话，那需要看日志的岗位就更多了。和上一问中提到的，测试、运维甚至运营都是有可能需要查看全部或者部分日志，并为他们的工作提供帮助。
| 岗位 |
日志用途 |
| 开发 |
开发调试、定位故障 |
| 测试 |
提交Bug的依据
了解程序运行关键点，设计更有针对性的测试用例 |
| 运维 |
反馈问题的依据
确定并排除基础问题（如配置错误导致系统无法启动等） |
| 运营 |
查看具体用户操作
帮助解决用户纠纷等 |
因此，一份越多人能看得懂、用得上的日志，是我们应当追求的目标。
1.3 不输出日志或者日志内容随意有什么危害？
答：各种想得到或者想不到的问题都会接踵而来
结合上面两问，这个问题的解答就变得显而易见了。
| 岗位 |
不打日志的危害 |
| 开发 |
开发过程遇到问题难以定位
-> 开发加班 |
| 测试 |
测试提交Bug描述笼统
-> 开发需要重现Bug
-> 没有日志问题难以定位
-> 加班
测试过程全黑盒
-> 测试无法设计出完备的测试用例
-> 系统上线后出现故障
-> 没有日志问题难以定位
-> 开发、测试加班 |
| 运维 |
出现任何问题都无法自行排查
-> 凡事都找开发
-> 没有日志问题难以定位
-> 开发、运维加班 |
| 运营 |
用户在使用过程中遇到问题
-> 用户并不记得或者不知道做了什么操作
-> 凡事都找开发
-> 没有日志问题难以定位
-> 开发加班 |
相信通过以上「日志三问」，读者应该能够理解本文有关日志的观点。接下来，就具体看一下如何输出日志。
2. 日志格式
一般来说，一行日志即一行文本。虽然日志本身并没有严格要求格式，但规范、统一的日志输出格式不仅可以方便阅读，也能便于各种日志系统搜集提取。
2.1 纯文本日志
纯文本日志是最常见，也最简单的日志输出形式。绝大多数编程语言中，都可以简单地print输出日志。
优点是可以完全自行规划格式，缺点就是不利于日志系统搜集提取。
一段典型的纯文本日志如下：
| Text Only |
|---|
| [I] [12-13 18:54:44] [web01] [TRACE-FD8CDE88] [ANONYMITY] [@ANONYMITY] [+0ms] [0ms] [REQUEST] host=`web01:8088`, method=`GET`, url=`/users`, query=`{"pageSize":"100"}`, originalUrl=`/users?pageSize=100`
[I] [12-13 18:54:44] [web01] [TRACE-FD8CDE88] [ANONYMITY] [@ANONYMITY] [+1ms] [0ms] [REQUEST FROM] ip=`172.16.35.1`, ips=``, remoteip=``, x-real-ip=``, x-forwarded-for=``, x-forwarded-proto=``, referer=`http://localhost:8081/`, browser=`Chrome`, version=`96.0.4664.93`, os=`OS X`, platform=`Apple Mac`
[I] [12-13 18:54:44] [web01] [TRACE-FD8CDE88] [u-admin] [@admin] [+1ms] [3ms] Auth by [username/password]: id=`u-admin`; username=`admin`
[I] [12-13 18:54:44] [web01] [TRACE-FD8CDE88] [u-admin] [@admin] [+1ms] [4ms] [REQUEST USER] 系统管理员(u-admin)
[D] [12-13 18:54:44] [web01] [TRACE-FD8CDE88] [u-admin] [@admin] [+1ms] [5ms] [MID] IN requestValidator
[D] [12-13 18:54:44] [web01] [TRACE-FD8CDE88] [u-admin] [@admin] [+2ms] [7ms] [MID] IN userModule
[D] [12-13 18:54:44] [web01] [TRACE-FD8CDE88] [u-admin] [@admin] [+2ms] [9ms] [RESPONSE] JSON: `{"ok":true,"error":200,"message":"","data":"<10 Records>","pageInfo":{"pagingStyle":"normal","pageSize":100,"count":10,"totalCount":10,"pageNumber":1,"pageCount":1,"isFirstPage":true},"traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","reqTime":"2021-12-13T10:54:44.896Z","respTime":"2021-12-13T10:54:44.905Z","reqCost":9}`, Length: 2794
|
这段日志主要分为2部分：
1. 自动生成的标签部分（[I] [2021-12-13 18:54:44] [web01] [TRACE-FD8CDE88] [ANONYMITY] [@ANONYMITY] [+0ms] [0ms]）
2. 具体编码输出内容部分（[REQUEST USER] 系统管理员(u-admin)）
这段日志主要诉求是方便阅读。因此，日志等级（[I]）、时间戳（[12-13 18:54:44]）、跟踪ID（TRACE-FD8CDE88）都做了缩短处理
2.2 JSON格式日志
把日志以JSON格式输出时，一般主要是为了方便日志系统搜集的考量。
优点自然是日志系统搜集方便，缺点是直接阅读时不太直观。
以上文中2.1 中的日志为例，以JSON格式输出时内容如下：
| Text Only |
|---|
| {"level":"INFO","timestamp":"2021-12-13T10:54:44Z","hostname":"web01","traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","userId":"ANONYMITY","username":"ANONYMITY","diffTime":0,"costTime":0,"message":"[REQUEST] host=`web01:8088`, method=`GET`, url=`/users`, query=`{\"pageSize\":\"100\"}`, originalUrl=`/users?pageSize=100`"}
{"level":"INFO","timestamp":"2021-12-13T10:54:44Z","hostname":"web01","traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","userId":"ANONYMITY","username":"ANONYMITY","diffTime":1,"costTime":0,"message":"[REQUEST FROM] ip=`172.16.35.1`, ips=``, remoteip=``, x-real-ip=``, x-forwarded-for=``, x-forwarded-proto=``, referer=`http://localhost:8081/`, browser=`Chrome`, version=`96.0.4664.93`, os=`OS X`, platform=`Apple Mac`"}
{"level":"INFO","timestamp":"2021-12-13T10:54:44Z","hostname":"web01","traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","userId":"u-admin","username":"admin","diffTime":1,"costTime":3,"message":"Auth by [username/password]: id=`u-admin`; username=`admin`"}
{"level":"INFO","timestamp":"2021-12-13T10:54:44Z","hostname":"web01","traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","userId":"u-admin","username":"admin","diffTime":1,"costTime":4,"message":"[REQUEST USER] 系统管理员(u-admin)"}
{"level":"DEBUG","timestamp":"2021-12-13T10:54:44Z","hostname":"web01","traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","userId":"u-admin","username":"admin","diffTime":1,"costTime":5,"message":"[MID] IN requestValidator"}
{"level":"DEBUG","timestamp":"2021-12-13T10:54:44Z","hostname":"web01","traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","userId":"u-admin","username":"admin","diffTime":2,"costTime":7,"message":"[MID] IN userModule"}
{"level":"DEBUG","timestamp":"2021-12-13T10:54:44Z","hostname":"web01","traceId":"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B","userId":"u-admin","username":"admin","diffTime":2,"costTime":9,"message":"[RESPONSE] JSON: `{\"ok\":true,\"error\":200,\"message\":\"\",\"data\":\"<10 Records>\",\"pageInfo\":{\"pagingStyle\":\"normal\",\"pageSize\":100,\"count\":10,\"totalCount\":10,\"pageNumber\":1,\"pageCount\":1,\"isFirstPage\":true},\"traceId\":\"TRACE-FD8CDE88-78AB-47E4-886A-85681700520B\",\"reqTime\":\"2021-12-13T10:54:44.896Z\",\"respTime\":\"2021-12-13T10:54:44.905Z\",\"reqCost\":9}`, Length: 2794"}
|
2.3 纯文本日志 vs. JSON格式日志
纯文本日志与JSON格式都有各自的优缺点。具体可以根据实际情况进行选择。
比如，开发的系统规模较小，系统为单体应用，没有复杂的处理，没有引入第三方日志系统等情况下，那纯文本足矣。而对于分布式系统、微服务场景、已经搭建好第三方日志系统的，则可以考虑使用JSON格式输出。
如果条件允许，可以改造业务系统的日志模块，使其可以根据配置输出不同格式的日志。实现在本地开发，不接入第三方日志系统时输出纯文本日志，而生产环境下则输出JSON格式日志。
3. 日志标签
在之前的例子里可以看到，除了在编码时指定的输出内容外，每条日志都具有相同字段的「标签」，这些通过这些标签可以区分每行日志的来源等基本信息。
可以说，没有标签的日志几乎没有任何价值。比如，在Web应用中，必然同时有多个用户、多个请求在访问系统。设想下面2个请求并发场景下输出的日志：
| Text Only |
|---|
| [TRACE-0000001] GET /users
[TRACE-0000002] GET /books
[TRACE-0000002] RESPONSE <10 records>
[TRACE-0000001] RESPONSE <3 records>
|
那么，通过traceId可以很清楚得看到，GET /users接口返回了3条数据，而GET /books接口返回了10条数据。
如果没有traceId标签，那么我们看到的日志就会像下面这样：
| Text Only |
|---|
| GET /users
GET /books
RESPONSE <10 records>
RESPONSE <3 records>
|
虽然和之前相比输出了同样内容的日志，但由于缺少traceId，大片日志完全混在了一起，即使我们去检查日志，只能非常孤立得去看每一行日志，而无法区分来自同一个请求的上下文日志。那么，这份日志显然用处就不大了。
下面举了一些常用的日志标签，根据实际情况，可以选择不同的组合来为每行日志加上标签，使得输出的日志可搜索、可筛选、可跟踪。
| 重要性 |
字段名 |
说明 |
|
appName |
应用名称 |
|
moduleName |
模块名称 |
|
upTime |
系统自启动起经过时间 |
| 重要 |
level |
日志等级，如：DEBUG, INFO, WARNING, ERROR |
|
levelShort |
日志等级简写，如：D, I, W, E |
| 重要 |
timestamp |
时间戳（秒），如：1503936000 |
|
timestampMs |
时间戳（毫秒），如：1503936000000 |
| 重要 |
timestampHumanized |
时间戳（可读格式），如：2017-08-29 00:00:00 |
|
timestampHumanizedShort |
时间戳（可读简化格式），如：08-29 00:00:00 |
|
hostname |
所在主机名 |
| 重要 |
traceId / requestId |
跟踪/请求ID，可以为UUID4，如：FD8CDE88-78AB-47E4-886A-85681700520B |
|
traceIdShort / requestIdShort |
跟踪/请求ID简写，可以为UUID第一段，如FD8CDE88 |
| 重要 |
userId |
用户ID，未登录用户可以固定为"ANONYMITY" |
| 重要 |
username |
用户名，未登录用户可以固定为"ANONYMITY" |
|
clientId |
客户端ID，浏览器可以通过在Cookies中写入实现 |
|
clientIP |
客户端IP地址 |
|
diffTime |
本条日志与上一条日志之间的时间间隔（毫秒），可用于简单判断耗时较长的代码范围 |
| 重要 |
costTime |
本次请求从开始到本条日志之间的时间间隔（毫秒），可用于简单判断耗时较长的代码范围 |
3.1 日志等级
上面提到的各种日志标签都比较好理解，这里需要单独提一下「日志等级」。
日志等级是一个非常容易产生混乱的部分。有些系统对日志等级的划分比较随意，甚至有时只是随便填写，比如不管什么日志都是DEBUG，任何「错误」都是ERROR。这么做会对后续查看、分析日志产生迷惑性，也会对第三方日志系统产生干扰。
为了合理设定每条日志的等级，首先我们得先确定一共有多少级别以及各自对应的问题严重程度。
| # |
日志级别 |
| 1 |
致命FATAL |
| 2 |
严重CRITICAL |
| 3 |
错误ERROR |
| 4 |
警告WARNING |
| 5 |
信息INFO |
| 6 |
调试DEBUG |
| 7 |
跟踪TRACE |
一般我们能见到的所有日志级别大概就是以上7种，但在具体不同的系统中，级别总数、划分方式会有所区别。
过多的级别也会增加开发负担，此外，各个级别所对应的内容也并没有严格的规定。在这里我们假设一个Web系统，其日志模块包含5个级别（CRITICAL、ERROR、WARNING、INFO、DEBUG）作为例子来进行说明。
严重 CRITICAL
完全无法预期的问题，错误会导致处理无法执行下去，甚至可能被抛出至运行时层面导致系统崩溃重启，如：
- 系统相关组件、包、配置文件缺失
- 获取本应存在的数据，但实际获取时数据缺失
- 执行SQL语句失败
产生此类问题时，如果系统依然可以返回HTTP响应，一般返回5xx服务器错误。
这个级别的问题必然是系统Bug，因此任何属于这类的问题都需要立刻被修复。
错误 ERROR
导致处理无法执行下去的问题，但不至于导致系统崩溃，错误也能在处理逻辑中捕捉，如：
- 调用第三方API报错
- 连接数据库失败
- 接口调用参数不正确
- 用户认证令牌过期导致认证失败
- 业务上不允许的操作，如重复录入数据等
产生此类问题时，一般系统依然可以返回HTTP响应，返回的同样也是5xx服务器错误。
这个级别的问题一般源于外部系统，并非本系统Bug。因此可能谈不上「修复」，更多的是「优化」，如:
- 调用第三方API失败时增加重试机制
- 优化UI避免用户输入非法内容或进行不允许的操作等。
警告 WARNING
一些算不上问题的「问题」，如：
- 访问不存在的路由、数据（即404，如
GET /favicon.ico）
- 各种用户名、密码、验证码错误
这类问题往往并不需要去修复，只要定期查看是否数量暴涨即可。产生此类问题的源头往往是爬虫系统、各种健康检查、漏洞扫描，但一般来说数量稳定，不太容易出现暴涨暴跌的情况。
信息 INFO
单纯记录提示信息，如：
| Text Only |
|---|
| [INFO] [2021-01-01 00:00:00] [张三] 创建了目录`/fav/books`
[INFO] [2021-01-01 00:00:00] [张三] 上传了文件`/fav/books/a.txt` (20KB)
[INFO] [2021-01-01 00:00:00] [张三] 删除了目录`/fav/books`
|
这个级别可以在测试环境中用于测试过程的跟踪，也可以在系统上线后作为用户数据分析，当然，也可以完全不输出此类日志。
调试 DEBUG
面向开发、测试级别的信息，在这类信息中会有详细的变量内容输出来帮助对程序进行调试，具体内容可参考下文。
4. 日志内容
日志内容即在编码时指定的输出内容，这部分内容相对自由，但一般也有一些技巧可以使用。
为了便于理解，以下示例代码均以 Python，使用 print() 输出为例。日志内容本身与具体所用语言/框架并无直接关联性
4.1 输出变量
在输出日志内容时，输出关键变量的内容是最常见的做法。但在实际项目中，很多人输出日志其实并不非常到位。
一个比较完备的变量输出例子如下：
| Python |
|---|
| import json
my_var1 = True # 布尔值的 true
my_var2 = 'True' # 字符串的 true
my_var3 = 'True ' # 字符串的 true，尾部有空格
print(f'my_var1={json.dumps(my_var1)}')
print(f'my_var2={json.dumps(my_var2)}')
print(f'my_var3={json.dumps(my_var3)}')
print(f'my_var3=[{my_var3}]')
|
输出如下：
| Text Only |
|---|
| my_var1=true
my_var2="True"
my_var3="True "
my_var3=[True ]
|
输出变量名
输出变量应当总是输出对应的变量名。
很多人习惯直接使用类似print(my_var)来输出日志，当日志量少的时候可能问题不大，当涉及循环、多个条件的复杂分支、随机数等，如果没有变量名作为提示，就很容易产生看不懂、看错等问题。如：
| Python |
|---|
| # 错误示例
import random, json
my_var1 = int(random.randint(0, 10))
my_var2 = int(random.randint(0, 10))
my_var3 = int(random.randint(0, 10))
print(f'{json.dumps(my_var1)}')
print(f'{json.dumps(my_var2)}')
print(f'{json.dumps(my_var3)}')
|
输出如下：
这种情况下，如果不对照这代码一行一行对比，根本没法知道各个变量是什么值
输出的变量值应当能表明类型
在输出变量值时，最容易混淆的就是，数字1和字符串"1"、布尔值true和字符串"true"这类问题，并且在 Javascript、Python 中最常见。忽略此问题有时会让日志内容看上去非常奇怪。如：
| Python |
|---|
| # 错误示例
is_ok = 'false'
print(f'is_ok={is_ok}')
if is_ok:
print("It's OK!")
|
输出如下：
这种情况下，日志中明明is_ok变量输出为假，但依然进入了分支内，非常诡异！
以 Python 为例，可以有多种方法将变量值类型表示出来：
| Python |
|---|
| import json
is_ok = 'false'
print(f'is_ok({type(is_ok)})={is_ok}') # 将变量值类型直接输出
print(f'is_ok={json.dumps(is_ok)}') # 将变量值序列化
is_ok = False
print(f'is_ok({type(is_ok)})={is_ok}') # 将变量值类型直接输出
print(f'is_ok={json.dumps(is_ok)}') # 将变量值序列化
|
输出如下：
| Text Only |
|---|
| is_ok(<class 'str'>)=false
is_ok="false"
is_ok(<class 'bool'>)=False
is_ok=false
|
输出的字符串应当能表明前后空格
在输出变量值时，另一个容易令人产生迷惑的就是字符串前后空格和不可见字符了。忽略此问题也会让日志看上去非常奇怪，如：
| Python |
|---|
| # 错误示例
my_var = 'main '
print(f'my_var={my_var}')
if my_var == 'main':
print("It's Main!")
else:
print("It's NOT Main!")
|
输出如下：
| Text Only |
|---|
| my_var=main
It's NOT Main!
|
这种情况下，日志中明明my_var变量输出为"main"，但依然进入了其他分支内，非常诡异！
以 Python 为例，可以有多种方法将字符串前后空格表示出来：
| Python |
|---|
| import json
my_var = 'main '
print(f'my_var=[{my_var}]') # 前后加入头尾标志符
print(f'my_var={json.dumps(my_var)}') # 按照JSON序列化（字符串需要""包裹）
|
输出如下：
| Text Only |
|---|
| my_var=[main ]
my_var="main "
|
输出的日期时间应当保留时区
在开发过程中，日期也是出问题的重灾区，由于开发本地机器、服务器所配置的时区可能并不相同，非常容易在日志中输出一些并不明确的日期，如：
| Python |
|---|
| # 错误示例
import time
print(time.strftime('time=%H:%M:%S', time.localtime(time.time())))
|
输出如下：
虽然输出的时间是「正确」的，但是很难判断这里的时间到底是北京时间还是 UTC 时间，不利于问题的排查
对于 Python 来说，输出符合 ISO 8601 标准的日期非常简单，如：
| Python |
|---|
| import arrow
print(f'time={arrow.now().isoformat()}')
|
输出如下：
| Text Only |
|---|
| time=2023-03-09T19:08:52.553436+08:00
|
4.2 调用关键函数、进入分支前输出日志
在了解如何输出变量之后，接下来就要考虑选择什么样的变量输出。
一般来说，关键函数、分支的判断依据需要输出，用来判断程序走向来定位问题。而程序处理过程中的大量中间变量则不需要输出，在开发时完全可以使用 Debug 单步调试等查看内容，如：
| Python |
|---|
| import json
my_var = 'mail'
print(f'[INFO] 根据类型发送不同的日志内容： my_var={json.dumps(my_var)}')
if my_var == 'mail':
print('[INFO] 发送邮件')
elif my_var == 'sms':
print('[INFO] 发送短信')
|
输出如下：
| Text Only |
|---|
| [INFO] 根据类型发送不同的日志内容： my_var="mail"
[INFO] 发送邮件
|
4.3 控制每行日志长度
由于输出日志本身也会消耗系统的资源，同时，过长的单行日志本身也可能存在设计上的问题。因此应当控制好每行日志的最大长度，避免为了「日志完整」而无脑输出日志，如：
| Python |
|---|
| # 错误示例
long_message = 'Bhlabala ' * 100
print('[INFO] ' + long_message)
|
输出如下：
| Text Only |
|---|
| [INFO] Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala
|
日志过长，不仅消耗系统资源，同时也难以阅读
因此，对于长内容，可以只输出关键部分，或者最开始部分等，避免无意义的超长日志，如：
| Python |
|---|
| long_message = 'Bhlabala ' * 100
print('[INFO] ' + long_message[0:50] + f'...(Length: {len(long_message)})')
|
输出如下：
| Text Only |
|---|
| [INFO] Bhlabala Bhlabala Bhlabala Bhlabala Bhlabala Bhlab...(Length: 900)
|
4.4 内容包含换行时的处理
有些日志内容本身包含了我们无法控制的换行，如报错时需要输出的函数调用堆栈列表。在JSON格式下整个内容都在message字段中并不会有什么问题，但如果以纯文本方式输出的话，会导致日志内容割裂，如：
| Python |
|---|
| # 错误示例
import traceback, arrow
try:
s = 'Hello'
s.run()
except Exception as e:
print(f'[ERROR] [{arrow.now().isoformat()}]', traceback.format_exc())
|
输出如下：
| Text Only |
|---|
| [ERROR] [2023-03-09T19:15:44.191318+08:00] Traceback (most recent call last):
File "tmp.py", line 5, in <module>
s.run()
AttributeError: 'str' object has no attribute 'run'
|
这时，无论是直接阅读，第三方日志系统搜集，还是单纯grep命令过滤日志文件，都非常容易被换行干扰
这时，可以对包含换行的日志内容按照换行符每行单独输出，保证每行都有「标签」，如：
| Python |
|---|
| import traceback, arrow
try:
s = 'Hello'
s.run()
except Exception as e:
for line in traceback.format_exc().splitlines():
print(f'[ERROR] [{arrow.now().isoformat()}]', line)
|
输出如下：
| Text Only |
|---|
| [ERROR] [2023-03-09T19:16:46.171732+08:00] Traceback (most recent call last):
[ERROR] [2023-03-09T19:16:46.171832+08:00] File "tmp.py", line 5, in <module>
[ERROR] [2023-03-09T19:16:46.171868+08:00] s.run()
[ERROR] [2023-03-09T19:16:46.171897+08:00] AttributeError: 'str' object has no attribute 'run'
|
后记
良好的日志输出不仅可以为自己和同事的工作提供帮助，同时也是系统可观测的重要一环。
本文中所提到的方法、设计不可能符合所有的系统，这里仅作为参考推荐给大家，希望能给大家提供有用的帮助。