logstash采集日志的时间格式探微
logstash 的时间格式问题，是一个老大难，当然，这种难往往来自于那种日志输出不规范的情况，尤其是时间戳，各种各样的，最终来到配置这一环节的时候，就要费很大的劲儿来调配这个东东。
所以，在立项新项目的时候，首先就需要约束好日志的格式，严格按照日志规范来走。
本文就来整理一下在配置 logstash 的时候，遇到时间格式的问题，所需要用到的，注意到的配置细节。
# 1，Date Filter 插件
日期过滤器 (opens new window)用于分析字段中的日期，然后使用该日期或时间戳作为事件的 logstash 时间戳。
# 2，配置项
该插件支持以下配置选项：
| Setting | Input type | Required | Default |
|---|---|---|---|
| locale | string | No | No |
| match | array | No | [] |
| tag_on_failure | array | No | ["_dateparsefailure"] |
| target | string | No | "@timestamp" |
| timezone | string | No | No |
接下来逐一详解各配置含义。
# 1，locate
值类型是字符串,这个设置没有默认值。使用 IETF-BCP47 或 POSIX 语言标记指定用于日期分析的区域设置。 简单的例子是 en，美国的 BCP47 或者 en_US 的 POSIX。大多数情况下需要设置语言环境来解析月份名称（MMM 模式）和星期几名称（EEE 模式）。如果未指定，则将使用平台默认值，但对于非英文平台默认情况下，英文解析器也将用作回退机制。
# 2，match
用于配置具体的匹配内容规则，前半部分内容表示匹配实际日志当中的时间戳的名称，后半部分则用于匹配实际日志当中的时间戳格式，这个地方是整条配置的核心内容，如果此处规则匹配是无效的，则生成后的日志时间戳将会被读取的时间替代。
这里列出一些常见的日志中时间格式的匹配规则，亲测可以直接放到实际中使用：
| 时间戳 | match |
|---|---|
| 2018-06-01T01:23:05+08:00 | yyyy-MM-dd'T'HH:mm:ss+08:00 |
| 2018-06-01T01:23:05Z | yyyy-MM-dd'T'HH:mm:ssZ |
| Jun 07 2018 01:23:05 | MMM dd yyyy HH:mm:ss (注: locale => "en") |
| Jun 7 2018 01:23:05 | MMM d yyyy HH:mm:ss (注: locale => "en") |
| 1529122935988 | UNIX_MS |
| 1529122935 | UNIX |
这块儿内容在最后会专门用实际例子进行说明。
date 插件支持五种时间格式
ISO8601属于标准格式，类似"2018-06-17T03:44:01.103Z"这样的格式。具体 Z 后面可以有"08:00"也可以没有，".103"这个也可以没有。常用场景里来说，Nginx的log_format配置里就可以使用$time_iso8601变量来记录请求时间成这种格式。UNIXUNIX 时间戳格式，记录的是从 1970 年起始至今的总秒数。Squid 的默认日志格式中就使用了这种格式。UNIX_MS这个时间戳则是从 1970 年起始至今的总毫秒数。据我所知，JavaScript 里经常使用这个时间格式。TAI64NTAI64N 格式比较少见，是这个样子的：@4000000052f88ea32489532c。我目前只知道常见应用中，qmail 会用这个格式。Joda-Time 库Logstash 内部使用了 Java 的 Joda 时间库 (opens new window)来作时间处理。所以我们可以使用 Joda 库所支持的时间格式来作具体定义。
时间戳详解
用于解析日期和时间文本的语法使用字母来指示时间值（月，分等）的类型，以及重复的字母来表示该值的形式（2 位月份，全月份名称等）。以下是可用于解析日期和时间的内容：
y(year)yyyy #全年号码。 例如：2015。 yy #两位数年份。 例如：2015年的15。1
2M(month of the year)M #最小数字月份。 例如：1 for January and 12 for December.。 MM #两位数月份。 如果需要，填充零。 例如：01 for January and 12 for Decembe MMM #缩短的月份文本。 例如： Jan for January。 注意：使用的语言取决于您的语言环境。 请参阅区域设置以了解如何更改语言。 MMMM #全月文本，例如：January。 注意：使用的语言取决于您的语言环境。1
2
3
4d(day of the month)d #最少数字的一天。 例如：1月份的第一天1。 dd #两位数的日子，如果需要的话可以填零.例如：01 for the 1st of the month。1
2H(hour of the day (24-hour clock))H #最小数字小时。 例如:0表示午夜。 HH #两位数小时，如果需要填零。 例如：午夜00。1
2m(minutes of the hour (60 minutes per hour))m #最小的数字分钟。 例如：0。 mm #两位数分钟，如果需要填零。 例如：00。1
2s(seconds of the minute (60 seconds per minute) )s #最小数字秒。 例如：0。 ss #两位数字，如果需要填零。 例如：00。1
2S秒的小数部分最大精度是毫秒（SSS）。 除此之外，零附加。S #十分之一秒。例如：0为亚秒值012 SS #百分之一秒 例如：01为亚秒值01 SSS #千分之一秒 例如：012为亚秒值0121
2
3Z 时区偏移或身份
Z #时区偏移，结构为HHmm（Zulu/UTC的小时和分钟偏移量）。例如：-0700。 ZZ #时区偏移结构为HH:mm（小时偏移和分钟偏移之间的冒号）。 例如：-07：00。 ZZZ #时区身份。 例如：America/Los_Angeles。 注意：有效的ID在列表中列出http://joda-time.sourceforge.net/timezones.html1
2
3
其他不常用的就不再详录了，诸上之外的，可参考：http://www.joda.org/joda-time/key_format.html
# 3，tag_on_failure
如果匹配失败，将值附加到 tag 字段，字段值为 _dateparsefailure，有时候我们在 kibana 当中看到日志会有这个字段，那么不用多想了，一定是时间格式匹配失败了，需要重新检查上边的 match 配置解析是否正确。
# 4，target
将匹配的时间戳存储到给定的目标字段中。如果未提供，则默认更新事件的@timestamp 字段。一般情况下，我们用的配置如下：
filter {
date {
match => [ "timestamp" , "dd/MMM/YYYY:HH:mm:ss Z", "UNIX", "yyyy-MM-dd HH:mm:ss", "dd-MMM-yyyy HH:mm:ss" ]
target => "@timestamp"
}
}
2
3
4
5
6
此处配置的意思是，match 对原始日志时间格式进行解析，解析之后，存储到下边定义的 target 定义的字段中，一般这个字段肯定是 @timestamp，而又因为默认字段就是@timestamp，因此这个字段可以省略，配置如下，效果一样。
filter {
date {
match => [ "timestamp" , "dd/MMM/YYYY:HH:mm:ss Z", "UNIX", "yyyy-MM-dd HH:mm:ss", "dd-MMM-yyyy HH:mm:ss" ]
}
}
2
3
4
5
# 5，timezone
当需要配置的 date 里面没有时区信息,而且不是 UTC 时间,需要设置 timezone 参数。
比如匹配北京时间 "2018-06-18 11:10:00"，则需要设置
date { match => ["logdate", "yyyy-MM-dd HH:mm:ss"] timezone => "Asia/Chongqing"}
- 东八区
| Standard Offset | Canonical ID | Aliases |
|---|---|---|
| +08:00 | Asia/Chongqing | Asia/Chungking |
| +08:00 | Asia/Hong_Kong | Hongkong |
| +08:00 | Asia/Shanghai | PRC |
附: timezone 列表 (opens new window)
# 3，几个解析实战（重点）
# 1，标准格式ISO8601
如果日志的格式是如上说明的这种标准格式，那么这种日志出来是最省事儿的，不需要进行额外的解析，直接拿来使用即可，最常见的案例就是 NGINX 的日志了。
# 1，原始日志。
一般情况下，我们会把 NGINX 日志 json 化，关于时间戳的配置，都是这样：
"@timestamp":"$time_iso8601"
然后输出的日志如下：
{
"@timestamp": "2019-10-12T21:57:40+08:00",
"host": "172.16.241.250",
"request_method": "GET",
"clientip": "42.236.99.65",
"size": 26977,
"responsetime": 0.258,
"upstreamtime": "0.258",
"upstreamhost": "unix:/tmp/php-cgi.sock",
"http_host": "wiki.eryajf.net",
"url": "/index.php",
"xff": "-",
"referer": "http://wiki.eryajf.net/pages/2217.html",
"agent": "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.4.2661.102 Safari/537.36; 360Spider",
"status": "200"
}
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
那么这种日志，就不需要添加 data 插件进行解析，刨除其他特殊解析之外，直接进行输入输出即可，测试效果如下。
# 2，配置文件。
此时可用如下配置文件：
input {
file {
path => ["/data/log/test.log"]
codec => "json"
}
}
output {
stdout {
codec => rubydebug
}
}
2
3
4
5
6
7
8
9
10
11
12
# 3，测试效果。
此时利用 rubydebug，查看控制台输出效果：
$ /usr/share/logstash/bin/logstash -f /usr/share/logstash/test.conf
。。。。。。
打印信息忽略
。。。。。。
{
"referer" => "http://wiki.eryajf.net/pages/2217.html",
"host" => "172.16.241.250",
"agent" => "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.4.2661.102 Safari/537.36; 360Spider",
"@timestamp" => 2019-10-12T13:57:40.000Z,
"xff" => "-",
"clientip" => "42.236.99.65",
"url" => "/index.php",
"upstreamtime" => "0.258",
"path" => "/data/log/test.log",
"size" => 26977,
"http_host" => "wiki.eryajf.net",
"@version" => "1",
"status" => "200",
"request_method" => "GET",
"responsetime" => 0.258,
"upstreamhost" => "unix:/tmp/php-cgi.sock"
}
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
此时可以看到，我们没有针对原始日志进行任何解析操作，原始日志中的@timestamp字段就自动被 logstash 识别作为了日志的@timestamp，非常方便便捷，而且在这一层也少了解析的步骤，对 logstash 负载是大有好处的，因此我们鼓励开发者使用这种标准格式进行日志的输出打印，当这成为一个标准之后，一切就显得优雅了。
# 2，带 T模式。
我也不知道这种日志具体的格式名称，总之它的特征就是在时间戳里边有一个 T，这个T并不代表任何含义，仅仅作为一个时间戳隔离的无含义字段，因此我们在解析的时候，也可以将其无含义对待，直接套用即可。
# 1，原始日志。
这个一般是开发者定义时间格式，然后输出的日志如下：
{"timestamp":"2019-10-10T15:37:08+08:00","level":"info","message":"这是一条测试日志"}
套用上边表格里边的内容，直接引用后边的 match 配置即可。
# 2，配置文件。
此时可用如下配置文件：
input {
file {
path => ["/data/log/test.log"]
codec => "json"
}
}
filter {
date {
# 直接将T作为一个占位符，后边的时间也是，不过可以用Z代替
match => [ "timestamp" , "yyyy-MM-dd'T'HH:mm:ss+08:00" ]
}
}
output {
stdout {
codec => rubydebug
}
}
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
# 3，测试效果。
此时利用 rubydebug，查看控制台输出效果：
$ /usr/share/logstash/bin/logstash -f /usr/share/logstash/test.conf
。。。。。。
打印信息忽略
。。。。。。
{
"@version" => "1",
"path" => "/data/log/test.log",
"host" => "localhost.localdomain",
"level" => "info",
"timestamp" => "2019-10-10T15:37:08+08:00",
"@timestamp" => 2019-10-10T07:37:08.000Z,
"message" => "这是一条测试日志"
}
2
3
4
5
6
7
8
9
10
11
12
13
14
15
生产当中，如果日志格式与上边例子一致，那么配置也是可以直接复用的，如果有出入，则应该根据实际情况进行特殊配置。
# 3，业务日志。
有一些应用的日志，或者业务的日志，时间格式极其不标准，各有各的想法，各有各的的模样，就像西游记里边长的各色各样的小妖一般，这种的处理起来就有点棘手了，需要借助于 grok 插件来进行处理。
# 1，原始日志。
这种就千奇百怪了，这里举一个例子，算是抛砖引玉，遇到一些相对特殊的，可以自行匹配转换，输出的日志如下：
[2019-09-17 17:35:30] ---.INFO: ===:{"code":0,"msg":"","nowTime":1565948130,"data":0}
# 2，配置文件。
此时可用如下配置文件：
input {
file {
path => ["/data/log/test.log"]
codec => "json"
}
}
filter {
grok {
match => [ "message", "\[%{YEAR:year}-%{MONTHNUM:month}-%{MONTHDAY:day} %{TIME:time}\]%{GREEDYDATA}"]
add_field => { "timestamp" => "%{year}-%{month}-%{day} %{time}" }
remove_field => [ "day", "month", "year", "time"]
}
date {
match => [ "timestamp" , "dd/MMM/YYYY:HH:mm:ss Z", "UNIX", "yyyy-MM-dd HH:mm:ss", "dd-MMM-yyyy HH:mm:ss" ]
target => "@timestamp"
remove_field => "timestamp"
}
}
output {
stdout {
codec => rubydebug
}
}
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
说明，这个地方，有必要用我个人理解到的，进行一下讲解，很多人都在分享着各种各样的配置，几乎从来没有人用通俗的话讲配置解析一下，而这样的事儿，恰恰又是我喜欢做的，因为这样在别人看到这里的时候，会更加容易有真实的收获。
grok
将非结构化事件数据分析到字段中。 这个工具非常适用于系统日志，Apache 和其他网络服务器日志，MySQL 日志，以及通常为人类而不是计算机消耗的任何日志格式。
match
这个概念不必介绍了，但是内部的意思值得说明一下，表示将整条日志放入到 message 这一字段中，其中，时间戳逐个匹配，匹配到的赋值给
"day", "month", "year", "time"。add_field
添加一个字段 timestamp，来承接刚刚解析的时间戳。即将
"day", "month", "year", "time"赋值 g 诶 timestamp。remove_field
当解析到的字段已经赋值给了新的字段，那么原来解析到的
"day", "month", "year", "time"就可以丢掉了。
date
再往下就比较熟悉了，不必多介绍了，也是本文一直在讲解的内容。
# 3，测试效果。
此时利用 rubydebug，查看控制台输出效果：
$ /usr/share/logstash/bin/logstash -f /usr/share/logstash/test.conf
。。。。。。
打印信息忽略
。。。。。。
{
"@version" => "1",
"host" => "localhost.localdomain",
"message" => "[2019-09-17 17:35:30] ---.INFO: ===:{\"code\":0,\"msg\":\"\",\"nowTime\":1565948130,\"data\":0}",
"path" => "/data/log/test.log",
"@timestamp" => 2019-09-17T09:35:30.000Z
}
2
3
4
5
6
7
8
9
10
11
12
13
这里的输出中，我们可以清晰看到，timestamp输出的时间，与原始日志中的时间是一致的，而且没有_dateparsefailure这个出现，说明解析规则是成功的。
# 4，系统日志 message。
有时候可能还需要采集系统的 message 日志，用于记录一些与系统相关的日志记录。
# 1，原始日志。
Linux 系统日志输出如下：
Oct 10 23:01:01 localhost systemd: Starting Session 9 of user root.
# 2，配置文件。
此时可用如下配置文件：
input {
file {
path => ["/data/log/test.log"]
}
}
filter {
grok {
match => {"message" => "%{SYSLOGLINE}"}
}
date {
match => ["timestamp","MMM dd HH:mm:ss"]
}
mutate {
remove_field => ["timestamp"]
}
}
output {
stdout {
codec => rubydebug
}
}
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
# 3，测试效果。
此时利用 rubydebug，查看控制台输出效果：
$ /usr/share/logstash/bin/logstash -f /usr/share/logstash/test.conf
。。。。。。
打印信息忽略
。。。。。。
{
"message" => [
[0] "Oct 10 23:01:01 localhost systemd: Starting Session 9 of user root.",
[1] "Starting Session 9 of user root."
],
"program" => "systemd",
"path" => "/data/log/test.log",
"@timestamp" => 2019-10-10T15:01:01.000Z,
"host" => "localhost.localdomain",
"@version" => "1",
"logsource" => "localhost"
}
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
这个配置，是借助于 elk 已经给出的一个插件 %{SYSLOGLINE}来完成，配置起来还是比较简便的。
好了，实际生产中实战的例子就举这么几个吧，常规的基本上都可用，如有其它比较特殊的，那么结合 grok 进行匹配即可。
# 4，时区问题
很多中国用户经常提一个问题：为什么 @timestamp 比我们早了 8 个小时？怎么修改成北京时间？
其实，Elasticsearch 内部(有相当多的软件，都是)，对时间类型字段，是统一采用 UTC 时间，存成 long 长整形数据的！对日志统一采用 UTC 时间存储，是国际安全/运维界的一个通识——欧美公司的服务器普遍广泛分布在多个时区里——不像中国，地域横跨五个时区却只用北京时间。
对于页面查看，ELK 的解决方案是在 Kibana 上，读取浏览器的当前时区，然后在页面上转换时间内容的显示。
所以，建议大家接受这种设定。否则，即便你用 .getLocalTime 修改，也还要面临在 Kibana 上反过去修改，以及 Elasticsearch 原有的 ["now-1h" TO "now"] 这种方便的搜索语句无法正常使用的尴尬。
|