【最佳实践】使用CloudLens排查日志时间解析错误问题

简介: 本文主要介绍如何使用CloudLens for SLS定位和解决iLogtail日常使用中的常见问题之一:日志时间解析错误问题。


1. 目标读者

数字化系统开发运维(DevOps)工程师、稳定性工程师(SRE)、可观测平台运维人员等。

2. 背景介绍

iLogtail 是阿里云日志服务(SLS)团队自研的可观测数据采集 Agent,拥有的轻量级、高性能、自动化配置等诸多生产级别特性,可以部署于物理机、虚拟机、Kubernetes 等多种环境中来采集遥测数据。目前 iLogtail 广泛应用于线上监控、问题分析/定位、运营分析、安全分析等多种场景,在实战中验证了其强大的性能和稳定性。

CloudLens for SLS是日志服务推出的一款应用,帮助用户监控和管理日志服务Project、Logstore等资产,提升用户对日志服务资产的管理效率、快速了解其消耗情况。

3. 使用场景

文件日志采集是日志采集Agent最常见的数据采集场景,iLogtail目前支持主机上文件采集以及容器场景下的文件采集。但是文件采集在实战中会遇到各种各样的问题,基于此场景,CloudLens for SLS集成了针对iLogtail的状态监控,可以实时的反馈当前iLogtail Agent的运行状况。

4. 问题描述

日志时间解析是日志采集中的一项常用功能,当用户希望使用日志中的时间作为实际存储记录的日志时间(Logtail默认使用日志采集时间作为实际存储记录的日志时间),或单纯地对日志中的时间进行格式变换时,都需要对日志中的时间字符串根据用户配置的时间格式进行解析。错误的时间格式将会导致解析失败,进而产生包括PARSE_TIME_FAIL_ALARM、GOTIME_PARSE_ALARM等在内的错误信息。

4.1 问题发现

打开CloudLens for SLS,在左侧的报表中心下拉菜单中选择“采集监控”,然后在右侧的页面中选择相应的Project,点击“Logtail异常监控”选项卡,此时会展示该Project下的所有采集异常信息:

截屏2022-11-18 11.32.37.png

其中,名为“日志时间解析错误(PARSE_TIME_FAIL_ALARM、GOTIME_PARSE_ALARM等)”的表格展示了Logtail在日志时间解析方面出现的问题,它会详细地说明问题原因,以及一些帮助排查问题的信息(如logstore,时间格式等)。

截屏2022-11-17 17.37.03.png

4.2 影响范围

该采集配置下时间解析失败的日志在SLS控制台的显示时间会与预期不一致,但不影响日志上报。

4.3 解决方案

如果您的日志中存在多种格式的时间字段,而您只选择解析数量占比最大的时间格式,则在解析其它时间格式时出现的错误可以忽略。如果您的日志中仅存在单一格式的时间字段,则需要根据下文具体场景来调整配置的时间格式以满足需求。

5. 控制台日志显示时间计算方式

场景

控制台日志显示时间

解析成功

解析失败

不启用插件配置解析时间

(下文中的场景一)

日志时间+控制台所在地区的时区偏移-自定义时区偏移

Logtail本地时间+控制台所在地区的时区偏移-自定义时区偏移

使用插件解析时间

(下文中的场景二&场景三)

Logtail本地时间+控制台所在地区的时区偏移

其中,东x区(即UTC+x)的时区偏移为x,西x区(即UTC-x)的时区偏移为-x。

6. 具体场景与方案建议

出现日志时间解析错误的原因有多种,这里将分场景逐个介绍错误情况以及可能的解决方法。

6.1 场景一:不使用插件进行时间解析

错误信息

PARSE_TIME_FAIL_ALARM:<日志时间> <配置的时间格式> flag: <时间格式是否为“%s”>

rest.png

影响范围

该采集配置下时间解析失败的日志在SLS控制台的显示时间会与预期不一致,但不影响日志上报,实际存储记录的日志时间的计算公式见附录。

错误原因

配置的时间格式与日志时间的实际格式不符。

解决方案

修改时间格式,使其与日志时间的实际格式相符。

示例

采集JSON日志,指定使用“time”字段的值作为实际存储记录的日志时,不使用机器时区(UTC)且设定自定义时区为东9区(UTC+9)。

日志样例如下:

{"time": "2022-11-1T10:32:05", "content": "this is a sample log"}

如果在采集配置界面配置如下时间格式:

截屏2022-11-04 13.15.08.png

则会产生PARSE_TIME_FAIL_ALARM,原因是日志中字段time的值“2022-11-1T10:32:05”不符合配置的时间格式“%Y-%m-%d %H:%M:%S”,此时该条日志仍将上传,且实际存储记录的日志时间为“2022-11-1 00:32:05”。

为了显示正确时间,应该将配置的时间格式修改为“%Y-%m-%dT%H:%M:%S”,即如下图所示:

截屏2022-11-04 13.18.03.png

6.2 场景二:使用processor_strptime插件进行时间解析

错误信息

STRPTIME_PARSE_ALARM:strptime(<日志时间>, <配置的时间格式>) failed: 0001-01-01 00:00:00 +0000 UTC, <错误信息>

str.png

影响范围

该采集配置下时间解析失败的日志在SLS控制台的显示时间会与预期不一致,但不影响日志上报,实际存储记录的日志时间的计算公式见附录。

错误原因

配置的时间格式与日志时间的实际格式不符。

解决方案

修改时间格式,使其与日志时间的实际格式相符。

示例

采集JSON日志,指定使用“time”字段的值作为实际存储记录的日志时间,并设定日志时区为东9区(UTC+9)。

日志样例如下:

{"time": "2022-11-1T10:32:05", "content": "this is a sample log"}

如果在采集配置界面配置如下左图的时间插件,则会产生STRPTIME_PARSE_ALARM,原因是日志中字段time的值“2022-11-1T10:32:05”不符合配置的时间格式“%Y-%m-%d %H:%M:%S”,此时该条日志仍将上传,且实际存储记录的日志时间为“2022-11-1 09:32:05”。为了显示正确时间,应该将配置的时间格式修改为“%Y-%m-%dT%H:%M:%S”,即如下右图所示。

截屏2022-11-18 10.31.58.png

6.3 场景三:使用processor_gotime插件进行时间解析或格式转换

子场景一:日志中不存在配置指定的时间字段

错误信息

GOTIME_FIND_ALARM:cannot find key <指定的时间字段名>

find.png

影响范围

该采集配置下的processor_gotime插件将不起效,插件输出和插件输入将保持一致,且不影响其它配置。

错误原因

日志中缺少指定的时间字段。

解决方案

确认日志中是否有指定的时间字段,如有,修改指定的时间字段名;若无,则请删除当前插件(即使用系统时间作为实际存储记录的日志时间)。

示例

采集JSON日志,将“time”字段存储的时间调整为东8区(UTC+8)并进行格式转换且保留“time”字段,同时指定使用“time”字段的值作为日志的显示时间,并设定日志时区为东9区(UTC+9)。

日志样例如下:

{"time": "2022-11-1T10:32:05", "content": "this is a sample log"}

如果在采集配置界面配置如下左图时间插件,则会产生GOTIME_FIND_ALARM,原因是日志中缺少“tim”字段。为了完成时间格式转换且显示正确时间,应该将时间字段修改为“time”,即如下右图所示。

截屏2022-11-18 10.37.39.png

则处理后的日志为

{"time": "2022-11-1T10:32:05", "content": "this is a sample log", "new_time": "20222/11/1 09:32:05"}

子场景二:待解析的日志时间是非Unix时间

错误信息

GOTIME_PARSE_ALARM:ParseInLocation(<配置的源时间格式>, <日志时间>, <配置的日志时间时区>) failed: <错误信息>

1.png

影响范围

  • 如果配置了时间格式转换功能(即配置了DestKey、DestFormat和DestLocation参数),则该采集配置下经过该插件处理后的日志中将缺少转换后的时间字段,不影响日志上报;

  • 如果配置了时间解析功能(即设定SetTime=true),则该采集配置下时间解析失败的日志在SLS控制台的显示时间会与预期不一致,但不影响日志上报,实际存储记录的日志时间的计算公式见附录。

错误原因

配置的时间格式与日志时间的实际格式不符。

解决方案

修改时间格式,使其与日志时间的实际格式相符。

示例

采集JSON日志,将“time”字段存储的时间调整为东8区(UTC+8)并进行格式转换且保留“time”字段,同时指定使用“time”字段的值作为实际存储记录的日志时间,并设定日志时区为东9区(UTC+9)。

日志样例如下:

{"time": "2022-11-1T10:32:05", "content": "this is a sample log"}

如果在采集配置界面配置如下左图时间插件,则会产生GOTIME_PARSE_ALARM,原因是日志中字段time的值“2022-11-1T10:32:05”不符合配置的时间格式“2006-01-02 15:04:05”,此时该条日志仍将上传,内容同源日志且实际存储记录的日志时间为“2022-11-1 09:32:05”。为了完成时间格式转换且显示正确时间,应该将配置的时间格式修改为“2006-01-02T15:04:05”,即如下右图所示。

截屏2022-11-18 10.36.05.png

则处理后的日志为

{"time": "2022-11-1T10:32:05", "content": "this is a sample log", "new_time": "20222/11/1 09:32:05"}

子场景三:待解析的日志时间是Unix时间

错误信息

GOTIME_PARSE_ALARM:ParseInt(<配置的源时间格式>, <日志时间>) failed: <错误信息>

图片 1.png

影响范围

  • 如果配置了时间格式转换功能(即配置了DestKey、DestFormat和DestLocation参数),则该采集配置下经过该插件处理后的日志中将缺少转换后的时间字段,不影响日志上报;

  • 如果配置了时间解析功能(即设定SetTime=true),则该采集配置下时间解析失败的日志在SLS控制台的显示时间会与预期不一致,但不影响日志上报,实际存储记录的日志时间的计算公式见附录。

错误原因

日志时间非Unix时间。

解决方案

检查指定的时间字段是否为Unix时间(纯整数),若不是,请调整时间字段。

示例

采集JSON日志,将“time”字段存储的时间调整为东8区(UTC+8)并进行格式转换且保留“time”字段,同时指定使用“time”字段的值作为实际存储记录的日志时间,并设定日志时区为东9区(UTC+9)。

日志样例如下:

{"time": "1667269925", "content": "this is a sample log"}

如果在采集配置界面配置如下左图时间插件,则会产生GOTIME_PARSE_ALARM,原因是日志中的“content”字段并不是Unix时间,此时该条日志仍将上传,内容同源日志且实际存储记录的日志时间为“2022-11-1 09:32:05”。为了完成时间格式转换且显示正确时间,应该将时间字段修改为“time”,即如下右图所示。截屏2022-11-18 10.36.48.png

则处理后的日志为

{"time": "2022-11-1T10:32:05", "content": "this is a sample log", "new_time": "20222/11/1 09:32:05"}

7. 关于iLogtail

iLogtail作为阿里云SLS提供的可观测数据采集器,可以运行在服务器、容器、K8s、嵌入式等多种环境,支持采集数百种可观测数据(日志、监控、Trace、事件等),已经有千万级的安装量。目前,iLogtail已正式开源,欢迎使用及参与共建。

GitHub

社区版文档

企业版官网

1660550445423-bac4f3a7-fdca-4c68-bae4-76fa16142f82.png

作者介绍
目录